-- Logs begin at Fri 2026-04-03 16:24:38 CEST, end at Fri 2026-04-03 21:33:42 CEST. -- Apr 03 21:32:01 volumio volumio[767]: info: Get:22 https://apt2.volumio.org/raspbian buster/main armhf g++ armhf 4:8.3.0-1+rpi2 [1632 B] Apr 03 21:32:01 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:01.900+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:01 volumio volumio[767]: info: Get:23 https://apt2.volumio.org/raspbian buster/main armhf make armhf 4.2.1-1.2 [321 kB] Apr 03 21:32:01 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:01.991+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:02 volumio volumio[767]: info: Get:24 https://apt2.volumio.org/raspbian buster/main armhf patch armhf 2.7.6-3+deb10u1 [115 kB] Apr 03 21:32:02 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:02.175+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:02 volumio go-librespot[1094]: time="2026-04-03T21:32:02+02:00" level=trace msg="sent dealer ping" Apr 03 21:32:02 volumio go-librespot[1094]: time="2026-04-03T21:32:02+02:00" level=trace msg="received dealer pong" Apr 03 21:32:02 volumio volumio[767]: info: CoreCommandRouter::volumioGetState Apr 03 21:32:02 volumio volumio[767]: info: Get:25 https://apt2.volumio.org/raspbian buster/main armhf dpkg-dev all 1.19.8 [1776 kB] Apr 03 21:32:02 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:02.423+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:03 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 03 21:32:03 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 03 21:32:03 volumio go-librespot[1094]: time="2026-04-03T21:32:03+02:00" level=debug msg="fetched chunk 15/15, size: 372682" uri="spotify:track:1CfsBC96b0vxey9aVAkQlg" Apr 03 21:32:04 volumio volumio[767]: info: Get:26 https://apt2.volumio.org/raspbian buster/main armhf build-essential armhf 12.6 [7568 B] Apr 03 21:32:04 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:04.171+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:04 volumio volumio[767]: info: Get:27 https://apt2.volumio.org/raspbian buster/main armhf dh-python all 3.20190308 [99.3 kB] Apr 03 21:32:04 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:04.280+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:04 volumio volumio[767]: info: Get:28 https://apt2.volumio.org/raspbian buster/main armhf libfakeroot armhf 1.23-1 [43.3 kB] Apr 03 21:32:04 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:04.449+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:04 volumio volumio[767]: info: Get:29 https://apt2.volumio.org/raspbian buster/main armhf fakeroot armhf 1.23-1 [85.2 kB] Apr 03 21:32:04 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:04.513+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:04 volumio volumio[767]: info: Get:30 https://apt2.volumio.org/raspbian buster/main armhf libalgorithm-diff-perl all 1.19.03-2 [47.9 kB] Apr 03 21:32:04 volumio volumio[767]: info: Get:31 https://apt2.volumio.org/raspbian buster/main armhf libalgorithm-diff-xs-perl armhf 0.04-5+b1 [11.4 kB] Apr 03 21:32:04 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:04.676+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:04 volumio volumio[767]: info: Get:32 https://apt2.volumio.org/raspbian buster/main armhf libalgorithm-merge-perl all 0.08-3 [12.7 kB] Apr 03 21:32:04 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:04.766+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:04 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:04.789+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:05 volumio volumio[767]: info: Get:33 https://apt2.volumio.org/raspbian buster/main armhf libexpat1-dev armhf 2.2.6-2+deb10u7 [130 kB] Apr 03 21:32:05 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:05.482+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:05 volumio volumio[767]: info: Get:34 https://apt2.volumio.org/raspbian buster/main armhf libpython3.7 armhf 3.7.3-2+deb10u7 [1252 kB] Apr 03 21:32:05 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:05.573+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:05 volumio volumio[767]: info: Get:35 https://apt2.volumio.org/raspbian buster/main armhf libpython3.7-dev armhf 3.7.3-2+deb10u7 [47.2 MB] Apr 03 21:32:06 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:06.016+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:12 volumio volumio[767]: info: CoreCommandRouter::volumioGetState Apr 03 21:32:12 volumio volumio[767]: info: Listing playlists Apr 03 21:32:12 volumio volumio[767]: info: Listing playlists Apr 03 21:32:19 volumio go-librespot[1094]: time="2026-04-03T21:32:19+02:00" level=debug msg="prefetching next track" uri="spotify:track:3OWoUTFewCAnGIkFHdL6KK" Apr 03 21:32:20 volumio go-librespot[1094]: time="2026-04-03T21:32:20+02:00" level=debug msg="selected format OGG_VORBIS_320 (abdf0b85494ca66b6cc2bc4be0bd5e3a4acb99ba)" uri="spotify:track:3OWoUTFewCAnGIkFHdL6KK" Apr 03 21:32:20 volumio go-librespot[1094]: time="2026-04-03T21:32:20+02:00" level=debug msg="requested aes key for file abdf0b85494ca66b6cc2bc4be0bd5e3a4acb99ba, gid: 3OWoUTFewCAnGIkFHdL6KK" Apr 03 21:32:20 volumio go-librespot[1094]: time="2026-04-03T21:32:20+02:00" level=trace msg="found 2 cdn urls" uri="spotify:track:3OWoUTFewCAnGIkFHdL6KK" Apr 03 21:32:21 volumio go-librespot[1094]: time="2026-04-03T21:32:21+02:00" level=debug msg="fetched first chunk of 13, total size is 6542443 bytes" uri="spotify:track:3OWoUTFewCAnGIkFHdL6KK" Apr 03 21:32:21 volumio go-librespot[1094]: time="2026-04-03T21:32:21+02:00" level=info msg="prefetched track \"the things that bring me joy\" (duration: 179047ms)" uri="spotify:track:3OWoUTFewCAnGIkFHdL6KK" Apr 03 21:32:22 volumio volumio[767]: info: CoreCommandRouter::volumioGetState Apr 03 21:32:23 volumio go-librespot[1094]: time="2026-04-03T21:32:23+02:00" level=debug msg="fetched chunk 1/12, size: 524288" uri="spotify:track:3OWoUTFewCAnGIkFHdL6KK" Apr 03 21:32:24 volumio go-librespot[1094]: time="2026-04-03T21:32:24+02:00" level=debug msg="fetched chunk 2/12, size: 524288" uri="spotify:track:3OWoUTFewCAnGIkFHdL6KK" Apr 03 21:32:24 volumio go-librespot[1094]: time="2026-04-03T21:32:24+02:00" level=debug msg="fetched chunk 3/12, size: 524288" uri="spotify:track:3OWoUTFewCAnGIkFHdL6KK" Apr 03 21:32:32 volumio volumio[767]: info: CoreCommandRouter::volumioGetState Apr 03 21:32:32 volumio go-librespot[1094]: time="2026-04-03T21:32:32+02:00" level=trace msg="sent dealer ping" Apr 03 21:32:32 volumio volumio[767]: info: Listing playlists Apr 03 21:32:32 volumio go-librespot[1094]: time="2026-04-03T21:32:32+02:00" level=trace msg="received dealer pong" Apr 03 21:32:32 volumio volumio[767]: info: Listing playlists Apr 03 21:32:35 volumio go-librespot[1094]: time="2026-04-03T21:32:35+02:00" level=debug msg="update volume requested to 51772/65535" Apr 03 21:32:35 volumio go-librespot[1094]: time="2026-04-03T21:32:35+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 03 21:32:35 volumio go-librespot[1094]: time="2026-04-03T21:32:35+02:00" level=trace msg="emitting websocket event: volume" Apr 03 21:32:35 volumio go-librespot[1094]: time="2026-04-03T21:32:35+02:00" level=debug msg="update volume requested to 39976/65535" Apr 03 21:32:35 volumio volumio[767]: SPOTIFY: received: {"type":"volume","data":{"value":79,"max":100}} Apr 03 21:32:35 volumio volumio[767]: SPOTIFY: RECEIVED SPOTIFY VOLUME 79 Apr 03 21:32:35 volumio volumio[767]: info: Setting Volumio Volume from Spotify: 79 Apr 03 21:32:35 volumio volumio[767]: info: VolumeController::SetAlsaVolume79 Apr 03 21:32:35 volumio go-librespot[1094]: time="2026-04-03T21:32:35+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 03 21:32:35 volumio go-librespot[1094]: time="2026-04-03T21:32:35+02:00" level=trace msg="emitting websocket event: volume" Apr 03 21:32:35 volumio go-librespot[1094]: time="2026-04-03T21:32:35+02:00" level=debug msg="update volume requested to 36699/65535" Apr 03 21:32:35 volumio volumio[767]: info: CoreStateMachine::pushState Apr 03 21:32:35 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 21:32:35 volumio volumio[767]: info: CoreCommandRouter::volumioPushState Apr 03 21:32:35 volumio go-librespot[1094]: time="2026-04-03T21:32:35+02:00" level=debug msg="update volume requested to 34078/65535" Apr 03 21:32:36 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:36.049+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.10.187:56810 @ 0x2a223c0" state=STATUS_PLAYING positionMs=183000 volume=79 Apr 03 21:32:36 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:36.052+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.10.187:56810 @ 0x2a223c0" id=spotify:track:1CfsBC96b0vxey9aVAkQlg title="When You're Gone" Apr 03 21:32:36 volumio volumio[767]: SPOTIFY: received: {"type":"volume","data":{"value":61,"max":100}} Apr 03 21:32:36 volumio volumio[767]: SPOTIFY: RECEIVED SPOTIFY VOLUME 61 Apr 03 21:32:36 volumio volumio[767]: info: Setting Volumio Volume from Spotify: 61 Apr 03 21:32:36 volumio volumio[767]: info: VolumeController::SetAlsaVolume61 Apr 03 21:32:36 volumio go-librespot[1094]: time="2026-04-03T21:32:36+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 03 21:32:36 volumio go-librespot[1094]: time="2026-04-03T21:32:36+02:00" level=trace msg="emitting websocket event: volume" Apr 03 21:32:36 volumio go-librespot[1094]: time="2026-04-03T21:32:36+02:00" level=debug msg="update volume requested to 31456/65535" Apr 03 21:32:36 volumio volumio[767]: info: CoreStateMachine::pushState Apr 03 21:32:36 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 21:32:36 volumio volumio[767]: info: CoreCommandRouter::volumioPushState Apr 03 21:32:36 volumio go-librespot[1094]: time="2026-04-03T21:32:36+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 03 21:32:36 volumio go-librespot[1094]: time="2026-04-03T21:32:36+02:00" level=trace msg="emitting websocket event: volume" Apr 03 21:32:36 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:36.499+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.10.187:56810 @ 0x2a223c0" state=STATUS_PLAYING positionMs=184000 volume=61 Apr 03 21:32:36 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:36.501+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.10.187:56810 @ 0x2a223c0" id=spotify:track:1CfsBC96b0vxey9aVAkQlg title="When You're Gone" Apr 03 21:32:36 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 79 Apr 03 21:32:36 volumio volumio[767]: SPOTIFY: SPOTIFY VOLUME 61 Apr 03 21:32:36 volumio volumio[767]: SPOTIFY: VOLUMIO VOLUME 79 Apr 03 21:32:36 volumio volumio[767]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 03 21:32:36 volumio volumio[767]: info: Setting Spotify Volume from Volumio: 79 Apr 03 21:32:36 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 61 Apr 03 21:32:36 volumio volumio[767]: SPOTIFY: SPOTIFY VOLUME 79 Apr 03 21:32:36 volumio volumio[767]: SPOTIFY: VOLUMIO VOLUME 61 Apr 03 21:32:36 volumio volumio[767]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 03 21:32:36 volumio volumio[767]: info: Setting Spotify Volume from Volumio: 61 Apr 03 21:32:36 volumio volumio[767]: SPOTIFY: received: {"type":"volume","data":{"value":52,"max":100}} Apr 03 21:32:36 volumio volumio[767]: SPOTIFY: RECEIVED SPOTIFY VOLUME 52 Apr 03 21:32:36 volumio volumio[767]: info: Setting Volumio Volume from Spotify: 52 Apr 03 21:32:36 volumio volumio[767]: info: VolumeController::SetAlsaVolume52 Apr 03 21:32:37 volumio volumio[767]: SPOTIFY: received: {"type":"volume","data":{"value":48,"max":100}} Apr 03 21:32:37 volumio volumio[767]: SPOTIFY: RECEIVED SPOTIFY VOLUME 48 Apr 03 21:32:37 volumio volumio[767]: info: Setting Volumio Volume from Spotify: 48 Apr 03 21:32:37 volumio volumio[767]: info: VolumeController::SetAlsaVolume48 Apr 03 21:32:37 volumio volumio[767]: info: CoreStateMachine::pushState Apr 03 21:32:37 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 21:32:37 volumio volumio[767]: info: CoreCommandRouter::volumioPushState Apr 03 21:32:37 volumio volumio[767]: info: CoreStateMachine::pushState Apr 03 21:32:37 volumio volumio[767]: info: CoreCommandRouter::volumioPushState Apr 03 21:32:37 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:37.918+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.10.187:56810 @ 0x2a223c0" state=STATUS_PLAYING positionMs=184000 volume=48 Apr 03 21:32:38 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:38.090+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.10.187:56810 @ 0x2a223c0" state=STATUS_PLAYING positionMs=184000 volume=48 Apr 03 21:32:38 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:38.099+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.10.187:56810 @ 0x2a223c0" id=spotify:track:1CfsBC96b0vxey9aVAkQlg title="When You're Gone" Apr 03 21:32:38 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:38.102+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.10.187:56810 @ 0x2a223c0" id=spotify:track:1CfsBC96b0vxey9aVAkQlg title="When You're Gone" Apr 03 21:32:38 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 48 Apr 03 21:32:38 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 48 Apr 03 21:32:38 volumio volumio[767]: SPOTIFY: SETTING SPOTIFY VOLUME 61 Apr 03 21:32:38 volumio volumio[767]: info: Sending Spotify command with payload to local API: /player/volume Apr 03 21:32:38 volumio go-librespot[1094]: time="2026-04-03T21:32:38+02:00" level=debug msg="update volume requested to 39976/65535" Apr 03 21:32:38 volumio go-librespot[1094]: time="2026-04-03T21:32:38+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 03 21:32:38 volumio go-librespot[1094]: time="2026-04-03T21:32:38+02:00" level=trace msg="emitting websocket event: volume" Apr 03 21:32:38 volumio volumio[767]: SPOTIFY: received: {"type":"volume","data":{"value":61,"max":100}} Apr 03 21:32:38 volumio volumio[767]: SPOTIFY: RECEIVED SPOTIFY VOLUME 61 Apr 03 21:32:38 volumio volumio[767]: info: Setting Volumio Volume from Spotify: 61 Apr 03 21:32:38 volumio volumio[767]: info: VolumeController::SetAlsaVolume61 Apr 03 21:32:38 volumio go-librespot[1094]: time="2026-04-03T21:32:38+02:00" level=debug msg="update volume requested to 34078/65535" Apr 03 21:32:38 volumio volumio[767]: info: CoreStateMachine::pushState Apr 03 21:32:38 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 21:32:38 volumio volumio[767]: info: CoreCommandRouter::volumioPushState Apr 03 21:32:38 volumio go-librespot[1094]: time="2026-04-03T21:32:38+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 03 21:32:38 volumio go-librespot[1094]: time="2026-04-03T21:32:38+02:00" level=trace msg="emitting websocket event: volume" Apr 03 21:32:38 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:38.874+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.10.187:56810 @ 0x2a223c0" state=STATUS_PLAYING positionMs=185000 volume=61 Apr 03 21:32:38 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:38.884+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.10.187:56810 @ 0x2a223c0" id=spotify:track:1CfsBC96b0vxey9aVAkQlg title="When You're Gone" Apr 03 21:32:38 volumio volumio[767]: SPOTIFY: received: {"type":"volume","data":{"value":52,"max":100}} Apr 03 21:32:38 volumio volumio[767]: SPOTIFY: RECEIVED SPOTIFY VOLUME 52 Apr 03 21:32:38 volumio volumio[767]: info: Setting Volumio Volume from Spotify: 52 Apr 03 21:32:38 volumio go-librespot[1094]: time="2026-04-03T21:32:38+02:00" level=debug msg="update volume requested to 39321/65535" Apr 03 21:32:38 volumio volumio[767]: info: VolumeController::SetAlsaVolume52 Apr 03 21:32:39 volumio go-librespot[1094]: time="2026-04-03T21:32:39+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 03 21:32:39 volumio go-librespot[1094]: time="2026-04-03T21:32:39+02:00" level=trace msg="emitting websocket event: volume" Apr 03 21:32:39 volumio volumio[767]: info: CoreStateMachine::pushState Apr 03 21:32:39 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 21:32:39 volumio volumio[767]: info: CoreCommandRouter::volumioPushState Apr 03 21:32:39 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:39.500+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.10.187:56810 @ 0x2a223c0" state=STATUS_PLAYING positionMs=185000 volume=52 Apr 03 21:32:39 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:39.521+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.10.187:56810 @ 0x2a223c0" id=spotify:track:1CfsBC96b0vxey9aVAkQlg title="When You're Gone" Apr 03 21:32:39 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 61 Apr 03 21:32:39 volumio volumio[767]: SPOTIFY: SPOTIFY VOLUME 52 Apr 03 21:32:39 volumio volumio[767]: SPOTIFY: VOLUMIO VOLUME 61 Apr 03 21:32:39 volumio volumio[767]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 03 21:32:39 volumio volumio[767]: info: Setting Spotify Volume from Volumio: 61 Apr 03 21:32:39 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 52 Apr 03 21:32:39 volumio volumio[767]: SPOTIFY: SPOTIFY VOLUME 61 Apr 03 21:32:39 volumio volumio[767]: SPOTIFY: VOLUMIO VOLUME 52 Apr 03 21:32:39 volumio volumio[767]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 03 21:32:39 volumio volumio[767]: info: Setting Spotify Volume from Volumio: 52 Apr 03 21:32:39 volumio volumio[767]: SPOTIFY: received: {"type":"volume","data":{"value":60,"max":100}} Apr 03 21:32:39 volumio volumio[767]: SPOTIFY: RECEIVED SPOTIFY VOLUME 60 Apr 03 21:32:39 volumio volumio[767]: info: Setting Volumio Volume from Spotify: 60 Apr 03 21:32:39 volumio volumio[767]: info: VolumeController::SetAlsaVolume60 Apr 03 21:32:40 volumio volumio[767]: info: CoreStateMachine::pushState Apr 03 21:32:40 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 21:32:40 volumio volumio[767]: info: CoreCommandRouter::volumioPushState Apr 03 21:32:40 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:40.155+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.10.187:56810 @ 0x2a223c0" state=STATUS_PLAYING positionMs=186000 volume=60 Apr 03 21:32:40 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:40.167+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.10.187:56810 @ 0x2a223c0" id=spotify:track:1CfsBC96b0vxey9aVAkQlg title="When You're Gone" Apr 03 21:32:40 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Apr 03 21:32:41 volumio volumio[767]: SPOTIFY: SETTING SPOTIFY VOLUME 52 Apr 03 21:32:41 volumio volumio[767]: info: Sending Spotify command with payload to local API: /player/volume Apr 03 21:32:41 volumio go-librespot[1094]: time="2026-04-03T21:32:41+02:00" level=debug msg="update volume requested to 34078/65535" Apr 03 21:32:41 volumio go-librespot[1094]: time="2026-04-03T21:32:41+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 03 21:32:41 volumio go-librespot[1094]: time="2026-04-03T21:32:41+02:00" level=trace msg="emitting websocket event: volume" Apr 03 21:32:41 volumio volumio[767]: SPOTIFY: received: {"type":"volume","data":{"value":52,"max":100}} Apr 03 21:32:41 volumio volumio[767]: SPOTIFY: RECEIVED SPOTIFY VOLUME 52 Apr 03 21:32:41 volumio volumio[767]: info: Setting Volumio Volume from Spotify: 52 Apr 03 21:32:41 volumio volumio[767]: info: VolumeController::SetAlsaVolume52 Apr 03 21:32:41 volumio volumio[767]: info: CoreStateMachine::pushState Apr 03 21:32:42 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 21:32:42 volumio volumio[767]: info: CoreCommandRouter::volumioPushState Apr 03 21:32:42 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:42.112+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.10.187:56810 @ 0x2a223c0" state=STATUS_PLAYING positionMs=187000 volume=52 Apr 03 21:32:42 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:42.173+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.10.187:56810 @ 0x2a223c0" id=spotify:track:1CfsBC96b0vxey9aVAkQlg title="When You're Gone" Apr 03 21:32:42 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 52 Apr 03 21:32:42 volumio volumio[767]: info: CoreCommandRouter::volumioGetState Apr 03 21:32:43 volumio volumio[767]: info: Get:36 https://apt2.volumio.org/raspbian buster/main armhf libpython3-dev armhf 3.7.3-1 [20.1 kB] Apr 03 21:32:43 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:43.973+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:44 volumio volumio[767]: info: Get:37 https://apt2.volumio.org/raspbian buster/main armhf python3-multidict armhf 4.5.2-1 [52.9 kB] Apr 03 21:32:44 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:44.134+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:44 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:44.243+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:44 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:44.323+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:44 volumio volumio[767]: info: Get:38 https://apt2.volumio.org/raspbian buster/main armhf python3-yarl armhf 1.3.0-1 [44.0 kB] Apr 03 21:32:44 volumio volumio[767]: info: Get:39 https://apt2.volumio.org/raspbian buster/main armhf python3-async-timeout all 3.0.1-1 [6292 B] Apr 03 21:32:44 volumio volumio[767]: info: Get:40 https://apt2.volumio.org/raspbian buster/main armhf python3-attr all 18.2.0-1 [37.3 kB] Apr 03 21:32:44 volumio volumio[767]: info: Get:41 https://apt2.volumio.org/raspbian buster/main armhf python3-aiohttp armhf 3.5.1-1+deb10u1 [241 kB] Apr 03 21:32:44 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:44.471+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:44 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:44.497+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:44 volumio volumio[767]: info: Get:42 https://apt2.volumio.org/raspbian buster/main armhf python3-asn1crypto all 0.24.0-1 [78.2 kB] Apr 03 21:32:44 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:44.656+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:44 volumio volumio[767]: info: Get:43 https://apt2.volumio.org/raspbian buster/main armhf python3-cffi-backend armhf 1.12.2-1 [70.1 kB] Apr 03 21:32:44 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:44.751+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:44 volumio volumio[767]: info: Get:44 https://apt2.volumio.org/raspbian buster/main armhf python3-crypto armhf 2.6.1-9+b1 [251 kB] Apr 03 21:32:44 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:44.866+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:44 volumio volumio[767]: info: Get:45 https://apt2.volumio.org/raspbian buster/main armhf python3-cryptography armhf 2.6.1-3+deb10u4 [184 kB] Apr 03 21:32:45 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:45.004+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:45 volumio volumio[767]: info: Get:46 https://apt2.volumio.org/raspbian buster/main armhf python3-dbus armhf 1.2.8-3 [95.9 kB] Apr 03 21:32:45 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:45.203+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:45 volumio volumio[767]: info: Get:47 https://apt2.volumio.org/raspbian buster/main armhf python3.7-dev armhf 3.7.3-2+deb10u7 [527 kB] Apr 03 21:32:45 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:45.339+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:45 volumio volumio[767]: info: Get:48 https://apt2.volumio.org/raspbian buster/main armhf python3-dev armhf 3.7.3-1 [1264 B] Apr 03 21:32:45 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:45.643+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:45 volumio volumio[767]: info: Get:49 https://apt2.volumio.org/raspbian buster/main armhf python3-entrypoints all 0.3-1 [5508 B] Apr 03 21:32:45 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:45.734+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:45 volumio volumio[767]: info: Get:50 https://apt2.volumio.org/raspbian buster/main armhf python3-gi armhf 3.30.4-1 [161 kB] Apr 03 21:32:45 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:45.788+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:45 volumio volumio[767]: info: Get:51 https://apt2.volumio.org/raspbian buster/main armhf python3-secretstorage all 2.3.1-2 [14.2 kB] Apr 03 21:32:45 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:45.887+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:45 volumio volumio[767]: info: Get:52 https://apt2.volumio.org/raspbian buster/main armhf python3-keyring all 17.1.1-1 [43.1 kB] Apr 03 21:32:46 volumio volumio[767]: info: Get:53 https://apt2.volumio.org/raspbian buster/main armhf python3-keyrings.alt all 3.1.1-1 [18.2 kB] Apr 03 21:32:46 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:46.011+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:46 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:46.051+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:46 volumio volumio[767]: info: Get:54 https://apt2.volumio.org/raspbian buster/main armhf python3-setuptools all 40.8.0-1 [306 kB] Apr 03 21:32:46 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:46.122+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:46 volumio volumio[767]: info: Get:55 https://apt2.volumio.org/raspbian buster/main armhf python3-wheel all 0.32.3-2 [19.4 kB] Apr 03 21:32:46 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:46.247+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:46 volumio volumio[767]: info: Get:56 https://apt2.volumio.org/raspbian buster/main armhf python3-xdg all 0.25-5 [35.9 kB] Apr 03 21:32:46 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:46.309+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:32:49 volumio volumio[767]: verbose: New Socket.io Connection to 192.168.10.181 from 192.168.10.187 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 6 Apr 03 21:32:49 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 03 21:32:50 volumio go-librespot[1094]: time="2026-04-03T21:32:49+02:00" level=trace msg="emitting websocket event: not_playing" Apr 03 21:32:50 volumio go-librespot[1094]: time="2026-04-03T21:32:49+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:3OWoUTFewCAnGIkFHdL6KK" Apr 03 21:32:50 volumio volumio[767]: info: CoreCommandRouter::volumioGetVisibleSources Apr 03 21:32:50 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 03 21:32:50 volumio volumio[767]: info: CoreCommandRouter::volumioGetState Apr 03 21:32:50 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 03 21:32:50 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 03 21:32:50 volumio volumio[767]: info: Received Get System Info Apr 03 21:32:50 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 03 21:32:50 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 03 21:32:50 volumio volumio[767]: info: Discovery: Getting this device information Apr 03 21:32:50 volumio volumio[767]: info: CoreCommandRouter::volumioGetState Apr 03 21:32:50 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 03 21:32:50 volumio volumio[767]: info: CoreCommandRouter::volumioGetState Apr 03 21:32:50 volumio go-librespot[1094]: time="2026-04-03T21:32:50+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 03 21:32:50 volumio go-librespot[1094]: time="2026-04-03T21:32:50+02:00" level=trace msg="emitting websocket event: will_play" Apr 03 21:32:50 volumio go-librespot[1094]: time="2026-04-03T21:32:50+02:00" level=info msg="loaded track \"the things that bring me joy\" (paused: false, position: 0ms, duration: 179047ms, prefetched: true)" uri="spotify:track:3OWoUTFewCAnGIkFHdL6KK" Apr 03 21:32:50 volumio volumio[767]: info: Listing playlists Apr 03 21:32:50 volumio go-librespot[1094]: time="2026-04-03T21:32:50+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 03 21:32:50 volumio go-librespot[1094]: time="2026-04-03T21:32:50+02:00" level=trace msg="scheduling prefetch in 149s" Apr 03 21:32:50 volumio go-librespot[1094]: time="2026-04-03T21:32:50+02:00" level=trace msg="emitting websocket event: metadata" Apr 03 21:32:50 volumio volumio[767]: info: CoreCommandRouter::volumioGetQueue Apr 03 21:32:50 volumio volumio[767]: info: CoreStateMachine::getQueue Apr 03 21:32:50 volumio volumio[767]: info: CorePlayQueue::getQueue Apr 03 21:32:50 volumio go-librespot[1094]: time="2026-04-03T21:32:50+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 03 21:32:50 volumio go-librespot[1094]: time="2026-04-03T21:32:50+02:00" level=trace msg="emitting websocket event: playing" Apr 03 21:32:50 volumio volumio[767]: SPOTIFY: received: {"type":"not_playing","data":{"context_uri":"spotify:playlist:37i9dQZF1DX2TRYkJECvfC","uri":"spotify:track:1CfsBC96b0vxey9aVAkQlg","play_origin":"playlist/ondemand"}} Apr 03 21:32:50 volumio volumio[767]: error: Failed to decode event: not_playing Apr 03 21:32:50 volumio volumio[767]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:playlist:37i9dQZF1DX2TRYkJECvfC","uri":"spotify:track:3OWoUTFewCAnGIkFHdL6KK","play_origin":"playlist/ondemand"}} Apr 03 21:32:50 volumio volumio[767]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:3OWoUTFewCAnGIkFHdL6KK","name":"the things that bring me joy","artist_names":["heylucas"],"album_name":"the things that bring me joy","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02da0707f085d8189c9da396f7","position":0,"duration":179047,"release_date":"year:2024 month:5 day:10","track_number":1,"disc_number":1}} Apr 03 21:32:50 volumio volumio[767]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:playlist:37i9dQZF1DX2TRYkJECvfC","uri":"spotify:track:3OWoUTFewCAnGIkFHdL6KK","resume":false,"play_origin":"playlist/ondemand"}} Apr 03 21:32:50 volumio volumio[767]: SPOTIFY: PUSH STATE SPOTIFY Apr 03 21:32:50 volumio volumio[767]: SPOTIFY: {"status":"play","service":"spop","title":"the things that bring me joy","artist":"heylucas","album":"the things that bring me joy","albumart":"https://i.scdn.co/image/ab67616d00001e02da0707f085d8189c9da396f7","uri":"spotify:track:3OWoUTFewCAnGIkFHdL6KK","trackType":"spotify","seek":0,"duration":179,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Apr 03 21:32:50 volumio volumio[767]: info: CoreCommandRouter::servicePushState Apr 03 21:32:50 volumio volumio[767]: info: CoreStateMachine::pushState Apr 03 21:32:50 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 21:32:50 volumio volumio[767]: info: CoreCommandRouter::volumioPushState Apr 03 21:32:51 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:51.032+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.10.187:56810 @ 0x2a223c0" state=STATUS_PLAYING positionMs=0 volume=52 Apr 03 21:32:51 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:51.051+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.10.187:56810 @ 0x2a223c0" id=spotify:track:3OWoUTFewCAnGIkFHdL6KK title="the things that bring me joy" Apr 03 21:32:51 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 03 21:32:51 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 52 Apr 03 21:32:51 volumio volumio[767]: SPOTIFY: PUSH STATE SPOTIFY Apr 03 21:32:51 volumio volumio[767]: SPOTIFY: {"status":"play","service":"spop","title":"the things that bring me joy","artist":"heylucas","album":"the things that bring me joy","albumart":"https://i.scdn.co/image/ab67616d00001e02da0707f085d8189c9da396f7","uri":"spotify:track:3OWoUTFewCAnGIkFHdL6KK","trackType":"spotify","seek":1000,"duration":179,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Apr 03 21:32:51 volumio volumio[767]: info: CoreCommandRouter::servicePushState Apr 03 21:32:51 volumio volumio[767]: info: CoreStateMachine::pushState Apr 03 21:32:51 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 21:32:51 volumio volumio[767]: info: CoreCommandRouter::volumioPushState Apr 03 21:32:51 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:51.389+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.10.187:56810 @ 0x2a223c0" state=STATUS_PLAYING positionMs=1000 volume=52 Apr 03 21:32:51 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:51.397+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.10.187:56810 @ 0x2a223c0" id=spotify:track:3OWoUTFewCAnGIkFHdL6KK title="the things that bring me joy" Apr 03 21:32:51 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 52 Apr 03 21:32:56 volumio volumio[767]: info: CoreCommandRouter::volumioGetState Apr 03 21:32:56 volumio volumio[767]: info: Listing playlists Apr 03 21:32:56 volumio volumio[767]: info: Listing playlists Apr 03 21:32:56 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 03 21:32:56 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 03 21:32:58 volumio volumio[767]: info: Fetched 84.3 MB in 1min 12s (1165 kB/s) Apr 03 21:32:58 volumio volumio5-onboarding[1194]: time=2026-04-03T21:32:58.979+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:33:00 volumio volumio[767]: info: Enabling plugin fusiondsp Apr 03 21:33:00 volumio volumio[767]: info: Loading plugin "fusiondsp"... Apr 03 21:33:02 volumio go-librespot[1094]: time="2026-04-03T21:33:02+02:00" level=trace msg="sent dealer ping" Apr 03 21:33:02 volumio go-librespot[1094]: time="2026-04-03T21:33:02+02:00" level=trace msg="received dealer pong" Apr 03 21:33:05 volumio go-librespot[1094]: time="2026-04-03T21:33:05+02:00" level=debug msg="fetched chunk 4/12, size: 524288" uri="spotify:track:3OWoUTFewCAnGIkFHdL6KK" Apr 03 21:33:07 volumio volumio[767]: info: Preparing to generate the ALSA configuration file Apr 03 21:33:08 volumio volumio[767]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 03 21:33:08 volumio volumio[767]: [169B blob data] Apr 03 21:33:08 volumio volumio5-onboarding[1194]: time=2026-04-03T21:33:08.772+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:33:08 volumio volumio[767]: [173B blob data] Apr 03 21:33:08 volumio volumio[767]: info: CoreCommandRouter::volumioGetState Apr 03 21:33:08 volumio volumio5-onboarding[1194]: time=2026-04-03T21:33:08.835+02:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Apr 03 21:33:09 volumio volumio[767]: info: Asound.conf file unchanged, so no further update is needed Apr 03 21:33:09 volumio volumio[767]: info: Output device has changed, restarting MPD Apr 03 21:33:09 volumio volumio[767]: info: Output device has changed, restarting Shairport Sync Apr 03 21:33:09 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 21:33:09 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 03 21:33:09 volumio go-librespot[1094]: time="2026-04-03T21:33:09+02:00" level=trace msg="received accesspoint ping" Apr 03 21:33:09 volumio go-librespot[1094]: time="2026-04-03T21:33:09+02:00" level=trace msg="received accesspoint pong ack" Apr 03 21:33:10 volumio sudo[10018]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 03 21:33:10 volumio sudo[10018]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 03 21:33:10 volumio sudo[10020]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 03 21:33:10 volumio sudo[10020]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 03 21:33:10 volumio sudo[10018]: pam_unix(sudo:session): session closed for user root Apr 03 21:33:10 volumio volumio[767]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 03 21:33:10 volumio volumio[767]: info: PLUGIN START: fusiondsp Apr 03 21:33:10 volumio volumio[767]: info: Loading i18n strings for locale de Apr 03 21:33:11 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Apr 03 21:33:11 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 21:33:11 volumio volumio[767]: info: FusionDsp - mixtype--------------------- Hardware Apr 03 21:33:11 volumio volumio[767]: info: Preparing to generate the ALSA configuration file Apr 03 21:33:11 volumio systemd[1]: Stopping Music Player Daemon... Apr 03 21:33:11 volumio volumio[767]: info: Done. Apr 03 21:33:12 volumio volumio[767]: info: FusionDsp - Apr 03 21:33:14 volumio volumio-remote-updater[378]: [2026-04-03 21:33:14] [disconnect] Disconnect close local:[1008,Pong timeout] remote:[1006] Apr 03 21:33:19 volumio volumio-remote-updater[378]: [2026-04-03 21:33:19] [connect] Successful connection Apr 03 21:33:20 volumio volumio[767]: info: camilladsp service started and running in background, instance 1 Apr 03 21:33:20 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 21:33:21 volumio volumio[767]: /bin/sh: 1: /data/plugins/audio_interface/fusiondsp/hw_params: not found Apr 03 21:33:21 volumio volumio[767]: error: FusionDsp - ----Hw detection failed :Error: Command failed: /data/plugins/audio_interface/fusiondsp/hw_params volumioHw >/data/configuration/audio_interface/fusiondsp/hwinfo.json Apr 03 21:33:21 volumio volumio[767]: /bin/sh: 1: /data/plugins/audio_interface/fusiondsp/hw_params: not found Apr 03 21:33:21 volumio volumio[767]: info: FusionDsp loaded Apr 03 21:33:21 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 03 21:33:22 volumio sudo[10068]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Apr 03 21:33:22 volumio sudo[10068]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 03 21:33:22 volumio volumio[767]: info: FusionDsp - Reporting Fusion DSP Enabled Apr 03 21:33:22 volumio volumio[767]: info: Adding Signal Path Element [object Object] Apr 03 21:33:22 volumio volumio[767]: info: Adding fusiondspeq DSP Signal Path Element Apr 03 21:33:22 volumio volumio[767]: info: FusionDsp - ---- installed callbackRead Apr 03 21:33:22 volumio volumio[767]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 03 21:33:22 volumio go-librespot[1094]: time="2026-04-03T21:33:22+02:00" level=debug msg="fetched chunk 5/12, size: 524288" uri="spotify:track:3OWoUTFewCAnGIkFHdL6KK" Apr 03 21:33:22 volumio sudo[10068]: pam_unix(sudo:session): session closed for user root Apr 03 21:33:23 volumio volumio[767]: Error: spawn /data/plugins/audio_interface/fusiondsp/camilladsp ENOENT Apr 03 21:33:23 volumio volumio[767]: at Process.ChildProcess._handle.onexit (internal/child_process.js:269:19) Apr 03 21:33:23 volumio volumio[767]: at onErrorNT (internal/child_process.js:465:16) Apr 03 21:33:23 volumio volumio[767]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Apr 03 21:33:23 volumio volumio[767]: at runNextTicks (internal/process/task_queues.js:62:3) Apr 03 21:33:23 volumio volumio[767]: at listOnTimeout (internal/timers.js:523:9) Apr 03 21:33:23 volumio volumio[767]: at processTimers (internal/timers.js:497:7) { Apr 03 21:33:23 volumio volumio[767]: errno: -2, Apr 03 21:33:23 volumio volumio[767]: code: 'ENOENT', Apr 03 21:33:23 volumio volumio[767]: syscall: 'spawn /data/plugins/audio_interface/fusiondsp/camilladsp', Apr 03 21:33:23 volumio volumio[767]: path: '/data/plugins/audio_interface/fusiondsp/camilladsp', Apr 03 21:33:23 volumio volumio[767]: spawnargs: [ Apr 03 21:33:23 volumio volumio[767]: '-p', Apr 03 21:33:23 volumio volumio[767]: 9876, Apr 03 21:33:23 volumio volumio[767]: '-o', Apr 03 21:33:23 volumio volumio[767]: '/tmp/camilladsp.log', Apr 03 21:33:23 volumio volumio[767]: '-l', Apr 03 21:33:23 volumio volumio[767]: 'warn', Apr 03 21:33:23 volumio volumio[767]: '/data/configuration/audio_interface/fusiondsp/camilladsp.yml' Apr 03 21:33:23 volumio volumio[767]: ] Apr 03 21:33:23 volumio volumio[767]: } Apr 03 21:33:23 volumio volumio[767]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 03 21:33:26 volumio systemd[1]: mpd.service: Succeeded. Apr 03 21:33:26 volumio systemd[1]: Stopped Music Player Daemon. Apr 03 21:33:26 volumio systemd[1]: Starting Music Player Daemon... Apr 03 21:33:27 volumio sudo[10072]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 03 21:33:27 volumio sudo[10072]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 03 21:33:28 volumio sudo[10072]: pam_unix(sudo:session): session closed for user root Apr 03 21:33:32 volumio volumio-remote-updater[378]: [2026-04-03 21:33:32] [connect] Successful connection Apr 03 21:33:32 volumio go-librespot[1094]: time="2026-04-03T21:33:32+02:00" level=trace msg="sent dealer ping" Apr 03 21:33:32 volumio go-librespot[1094]: time="2026-04-03T21:33:32+02:00" level=trace msg="received dealer pong" Apr 03 21:33:37 volumio go-librespot[1094]: time="2026-04-03T21:33:37+02:00" level=debug msg="handling pause player command from 056b5fa0bacdc74770cbbfefc08217ff61d5bd93" Apr 03 21:33:37 volumio go-librespot[1094]: time="2026-04-03T21:33:37+02:00" level=debug msg="pause track at 44243ms" Apr 03 21:33:37 volumio go-librespot[1094]: time="2026-04-03T21:33:37+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 03 21:33:37 volumio go-librespot[1094]: time="2026-04-03T21:33:37+02:00" level=debug msg="sending successful reply for dealer request" Apr 03 21:33:37 volumio go-librespot[1094]: time="2026-04-03T21:33:37+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 03 21:33:37 volumio go-librespot[1094]: time="2026-04-03T21:33:37+02:00" level=trace msg="emitting websocket event: paused" Apr 03 21:33:42 volumio sudo[10134]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-04-03 21:32 Apr 03 21:33:42 volumio sudo[10134]: 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="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="464fc672d77d3df6ee72b331d36cdf1fa936e1ec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 10:59:40 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="37c6ab864cb114e1344d540995c69f86"