Oct 13 23:47:00 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 13 23:47:00 bedroom-speakers volumio[19557]: info: Received Get System Info Oct 13 23:47:00 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 13 23:47:00 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 13 23:47:00 bedroom-speakers volumio[19557]: info: Discovery: Getting this device information Oct 13 23:47:00 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioGetState Oct 13 23:47:00 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 13 23:47:00 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 13 23:47:00 bedroom-speakers volumio[19557]: info: Received Get System Info Oct 13 23:47:00 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 13 23:47:00 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 13 23:47:00 bedroom-speakers volumio[19557]: info: Discovery: Getting this device information Oct 13 23:47:00 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioGetState Oct 13 23:47:00 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 13 23:47:07 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:07.239-06:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" latency=35.201669ms timeout=3s volume=23 Oct 13 23:47:07 bedroom-speakers volumio[19557]: info: VolumeController::SetAlsaVolume23 Oct 13 23:47:07 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioGetState Oct 13 23:47:07 bedroom-speakers volumio[19557]: info: CoreStateMachine::pushState Oct 13 23:47:07 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 23:47:07 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioPushState Oct 13 23:47:07 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:07.252-06:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" state=STATUS_PLAYING positionMs=204769 volume=23 Oct 13 23:47:07 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:07.252-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" id=spotify:track:2nGFzvICaeEWjIrBrL2RAx title="Put Your Records On" Oct 13 23:47:07 bedroom-speakers volumio[19557]: SPOTIFY: RECEIVED VOLUMIO VOLUME 23 Oct 13 23:47:07 bedroom-speakers volumio[19557]: SPOTIFY: SPOTIFY VOLUME 21 Oct 13 23:47:07 bedroom-speakers volumio[19557]: SPOTIFY: VOLUMIO VOLUME 23 Oct 13 23:47:07 bedroom-speakers volumio[19557]: SPOTIFY: DELTA VOLUME ENOUGH: true Oct 13 23:47:07 bedroom-speakers volumio[19557]: info: Setting Spotify Volume from Volumio: 23 Oct 13 23:47:08 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:08.193-06:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" latency=40.71953ms timeout=3s volume=24 Oct 13 23:47:08 bedroom-speakers volumio[19557]: info: VolumeController::SetAlsaVolume24 Oct 13 23:47:08 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioGetState Oct 13 23:47:08 bedroom-speakers volumio[19557]: info: CoreStateMachine::pushState Oct 13 23:47:08 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 23:47:08 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioPushState Oct 13 23:47:08 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:08.207-06:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" state=STATUS_PLAYING positionMs=205769 volume=24 Oct 13 23:47:08 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:08.208-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" id=spotify:track:2nGFzvICaeEWjIrBrL2RAx title="Put Your Records On" Oct 13 23:47:08 bedroom-speakers volumio[19557]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Oct 13 23:47:08 bedroom-speakers volumio[19557]: SPOTIFY: SPOTIFY VOLUME 23 Oct 13 23:47:08 bedroom-speakers volumio[19557]: SPOTIFY: VOLUMIO VOLUME 24 Oct 13 23:47:08 bedroom-speakers volumio[19557]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 23:47:08 bedroom-speakers volumio[19557]: SPOTIFY: SETTING SPOTIFY VOLUME 23 Oct 13 23:47:08 bedroom-speakers volumio[19557]: info: Sending Spotify command with payload to local API: /player/volume Oct 13 23:47:08 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:08-06:00" level=debug msg="update volume requested to 15073/65535" Oct 13 23:47:08 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:08-06:00" level=debug msg="put connect state because VOLUME_CHANGED" Oct 13 23:47:08 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:08-06:00" level=trace msg="emitting websocket event: volume" Oct 13 23:47:08 bedroom-speakers volumio[19557]: SPOTIFY: received: {"type":"volume","data":{"value":23,"max":100}} Oct 13 23:47:08 bedroom-speakers volumio[19557]: SPOTIFY: RECEIVED SPOTIFY VOLUME 23 Oct 13 23:47:11 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:11-06:00" level=trace msg="sent dealer ping" Oct 13 23:47:11 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:11-06:00" level=trace msg="received dealer pong" Oct 13 23:47:13 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:13.263-06:00 level=INFO msg="player skip next request" component=server type=REQUEST_TYPE_PLAYER_SKIP_NEXT peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" latency=49.828228ms timeout=10s Oct 13 23:47:13 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioNext Oct 13 23:47:13 bedroom-speakers volumio[19557]: info: CoreStateMachine::next Oct 13 23:47:13 bedroom-speakers volumio[19557]: info: Spotify next Oct 13 23:47:13 bedroom-speakers volumio[19557]: info: Sending Spotify command to local API: /player/next Oct 13 23:47:13 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:13-06:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:4jQqM4NI79HEcWHUJb8Hvf" Oct 13 23:47:13 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:13-06:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 23:47:13 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:13-06:00" level=trace msg="emitting websocket event: will_play" Oct 13 23:47:13 bedroom-speakers volumio[19557]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:playlist:37i9dQZF1F5p3rmiWPIYgZ","uri":"spotify:track:4jQqM4NI79HEcWHUJb8Hvf","play_origin":"playlist"}} Oct 13 23:47:13 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:13-06:00" level=debug msg="selected format OGG_VORBIS_320 (00200acc49ee52f3643f1360625e181915c58cf9)" uri="spotify:track:4jQqM4NI79HEcWHUJb8Hvf" Oct 13 23:47:13 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:13-06:00" level=debug msg="requested aes key for file 00200acc49ee52f3643f1360625e181915c58cf9, gid: 7rbECVPkY5UODxoOUVKZnA" Oct 13 23:47:13 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:13-06:00" level=trace msg="found 2 cdn urls" uri="spotify:track:4jQqM4NI79HEcWHUJb8Hvf" Oct 13 23:47:13 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:13-06:00" level=debug msg="fetched first chunk of 19, total size is 9535984 bytes" uri="spotify:track:4jQqM4NI79HEcWHUJb8Hvf" Oct 13 23:47:13 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:13-06:00" level=info msg="loaded track \"I Wonder\" (paused: false, position: 0ms, duration: 243440ms, prefetched: false)" uri="spotify:track:4jQqM4NI79HEcWHUJb8Hvf" Oct 13 23:47:13 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:13-06:00" level=debug msg="fetched chunk 2/18, size: 524288" uri="spotify:track:4jQqM4NI79HEcWHUJb8Hvf" Oct 13 23:47:13 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:13-06:00" level=debug msg="fetched chunk 1/18, size: 524288" uri="spotify:track:4jQqM4NI79HEcWHUJb8Hvf" Oct 13 23:47:13 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:13-06:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 23:47:13 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:13-06:00" level=trace msg="scheduling prefetch in 213s" Oct 13 23:47:13 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:13-06:00" level=trace msg="emitting websocket event: metadata" Oct 13 23:47:13 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:13-06:00" level=trace msg="emitting websocket event: not_playing" Oct 13 23:47:13 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:13-06:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:5xYC48nOppVemY6U5GRGTb" Oct 13 23:47:13 bedroom-speakers volumio[19557]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:7rbECVPkY5UODxoOUVKZnA","name":"I Wonder","artist_names":["Kanye West"],"album_name":"Graduation","album_cover_url":"https://i.scdn.co/image/ab67616d00001e029bbd79106e510d13a9a5ec33","position":0,"duration":243440,"release_date":"year:2007 month:9 day:11","track_number":4,"disc_number":1}} Oct 13 23:47:13 bedroom-speakers volumio[19557]: SPOTIFY: received: {"type":"not_playing","data":{"context_uri":"spotify:playlist:37i9dQZF1F5p3rmiWPIYgZ","uri":"spotify:track:4jQqM4NI79HEcWHUJb8Hvf","play_origin":"playlist"}} Oct 13 23:47:13 bedroom-speakers volumio[19557]: error: Failed to decode event: not_playing Oct 13 23:47:13 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:13-06:00" level=debug msg="fetched chunk 3/18, size: 524288" uri="spotify:track:4jQqM4NI79HEcWHUJb8Hvf" Oct 13 23:47:13 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:13-06:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 23:47:13 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:13-06:00" level=trace msg="emitting websocket event: will_play" Oct 13 23:47:13 bedroom-speakers volumio[19557]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:playlist:37i9dQZF1F5p3rmiWPIYgZ","uri":"spotify:track:5xYC48nOppVemY6U5GRGTb","play_origin":"playlist"}} Oct 13 23:47:14 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:14-06:00" level=debug msg="selected format OGG_VORBIS_320 (b31027d8e28b2175c5c0b3e0f777bf6afd37bd9c)" uri="spotify:track:5xYC48nOppVemY6U5GRGTb" Oct 13 23:47:14 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:14-06:00" level=debug msg="requested aes key for file b31027d8e28b2175c5c0b3e0f777bf6afd37bd9c, gid: 5p3SJ3CYqrmFbboAtfNo5n" Oct 13 23:47:14 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:14-06:00" level=trace msg="found 2 cdn urls" uri="spotify:track:5xYC48nOppVemY6U5GRGTb" Oct 13 23:47:14 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:14-06:00" level=debug msg="fetched first chunk of 17, total size is 8895112 bytes" uri="spotify:track:5xYC48nOppVemY6U5GRGTb" Oct 13 23:47:14 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:14-06:00" level=info msg="loaded track \"Memories (feat. Kid Cudi)\" (paused: false, position: 0ms, duration: 210853ms, prefetched: false)" uri="spotify:track:5xYC48nOppVemY6U5GRGTb" Oct 13 23:47:14 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:14-06:00" level=debug msg="fetched chunk 1/16, size: 524288" uri="spotify:track:5xYC48nOppVemY6U5GRGTb" Oct 13 23:47:14 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:14-06:00" level=debug msg="fetched chunk 3/16, size: 524288" uri="spotify:track:5xYC48nOppVemY6U5GRGTb" Oct 13 23:47:14 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:14-06:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 23:47:14 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:14-06:00" level=trace msg="scheduling prefetch in 181s" Oct 13 23:47:14 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:14-06:00" level=trace msg="emitting websocket event: metadata" Oct 13 23:47:14 bedroom-speakers volumio[19557]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5p3SJ3CYqrmFbboAtfNo5n","name":"Memories (feat. Kid Cudi)","artist_names":["David Guetta","Kid Cudi"],"album_name":"One More Love","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02f45c50e7cff5f2376c1e36ea","position":0,"duration":210853,"release_date":"year:2010 month:11 day:22","track_number":4,"disc_number":1}} Oct 13 23:47:14 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:14-06:00" level=debug msg="fetched chunk 2/16, size: 524288" uri="spotify:track:5xYC48nOppVemY6U5GRGTb" Oct 13 23:47:14 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:14-06:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 23:47:14 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:14-06:00" level=trace msg="emitting websocket event: playing" Oct 13 23:47:14 bedroom-speakers volumio[19557]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:playlist:37i9dQZF1F5p3rmiWPIYgZ","uri":"spotify:track:5xYC48nOppVemY6U5GRGTb","resume":false,"play_origin":"playlist"}} Oct 13 23:47:14 bedroom-speakers volumio[19557]: SPOTIFY: PUSH STATE SPOTIFY Oct 13 23:47:14 bedroom-speakers volumio[19557]: SPOTIFY: {"status":"play","service":"spop","title":"Memories (feat. Kid Cudi)","artist":"David Guetta, Kid Cudi","album":"One More Love","albumart":"https://i.scdn.co/image/ab67616d00001e02f45c50e7cff5f2376c1e36ea","uri":"spotify:track:5p3SJ3CYqrmFbboAtfNo5n","trackType":"spotify","seek":0,"duration":210,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Oct 13 23:47:14 bedroom-speakers volumio[19557]: info: CoreCommandRouter::servicePushState Oct 13 23:47:14 bedroom-speakers volumio[19557]: info: CoreStateMachine::pushState Oct 13 23:47:14 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 23:47:14 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioPushState Oct 13 23:47:14 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:14.587-06:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" state=STATUS_PLAYING positionMs=0 volume=24 Oct 13 23:47:14 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:14.587-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" id=spotify:track:5p3SJ3CYqrmFbboAtfNo5n title="Memories (feat. Kid Cudi)" Oct 13 23:47:14 bedroom-speakers volumio[19557]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Oct 13 23:47:14 bedroom-speakers volumio[19557]: SPOTIFY: SPOTIFY VOLUME 23 Oct 13 23:47:14 bedroom-speakers volumio[19557]: SPOTIFY: VOLUMIO VOLUME 24 Oct 13 23:47:14 bedroom-speakers volumio[19557]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 23:47:14 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:14-06:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 23:47:14 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:14-06:00" level=trace msg="emitting websocket event: playing" Oct 13 23:47:14 bedroom-speakers volumio[19557]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:playlist:37i9dQZF1F5p3rmiWPIYgZ","uri":"spotify:track:5xYC48nOppVemY6U5GRGTb","resume":false,"play_origin":"playlist"}} Oct 13 23:47:14 bedroom-speakers volumio[19557]: SPOTIFY: PUSH STATE SPOTIFY Oct 13 23:47:14 bedroom-speakers volumio[19557]: SPOTIFY: {"status":"play","service":"spop","title":"Memories (feat. Kid Cudi)","artist":"David Guetta, Kid Cudi","album":"One More Love","albumart":"https://i.scdn.co/image/ab67616d00001e02f45c50e7cff5f2376c1e36ea","uri":"spotify:track:5p3SJ3CYqrmFbboAtfNo5n","trackType":"spotify","seek":0,"duration":210,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Oct 13 23:47:14 bedroom-speakers volumio[19557]: info: CoreCommandRouter::servicePushState Oct 13 23:47:14 bedroom-speakers volumio[19557]: info: CoreStateMachine::pushState Oct 13 23:47:14 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioPushState Oct 13 23:47:14 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:14.684-06:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" state=STATUS_PLAYING positionMs=0 volume=24 Oct 13 23:47:14 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:14.684-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" id=spotify:track:5p3SJ3CYqrmFbboAtfNo5n title="Memories (feat. Kid Cudi)" Oct 13 23:47:14 bedroom-speakers volumio[19557]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Oct 13 23:47:14 bedroom-speakers volumio[19557]: SPOTIFY: SPOTIFY VOLUME 23 Oct 13 23:47:14 bedroom-speakers volumio[19557]: SPOTIFY: VOLUMIO VOLUME 24 Oct 13 23:47:14 bedroom-speakers volumio[19557]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 23:47:14 bedroom-speakers volumio[19557]: SPOTIFY: PUSH STATE SPOTIFY Oct 13 23:47:14 bedroom-speakers volumio[19557]: SPOTIFY: {"status":"play","service":"spop","title":"Memories (feat. Kid Cudi)","artist":"David Guetta, Kid Cudi","album":"One More Love","albumart":"https://i.scdn.co/image/ab67616d00001e02f45c50e7cff5f2376c1e36ea","uri":"spotify:track:5p3SJ3CYqrmFbboAtfNo5n","trackType":"spotify","seek":1000,"duration":210,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Oct 13 23:47:14 bedroom-speakers volumio[19557]: info: CoreCommandRouter::servicePushState Oct 13 23:47:14 bedroom-speakers volumio[19557]: info: CoreStateMachine::pushState Oct 13 23:47:14 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 23:47:14 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioPushState Oct 13 23:47:14 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:14.887-06:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" state=STATUS_PLAYING positionMs=1000 volume=24 Oct 13 23:47:14 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:14.887-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" id=spotify:track:5p3SJ3CYqrmFbboAtfNo5n title="Memories (feat. Kid Cudi)" Oct 13 23:47:14 bedroom-speakers volumio[19557]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Oct 13 23:47:14 bedroom-speakers volumio[19557]: SPOTIFY: SPOTIFY VOLUME 23 Oct 13 23:47:14 bedroom-speakers volumio[19557]: SPOTIFY: VOLUMIO VOLUME 24 Oct 13 23:47:14 bedroom-speakers volumio[19557]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 23:47:14 bedroom-speakers volumio[19557]: SPOTIFY: PUSH STATE SPOTIFY Oct 13 23:47:14 bedroom-speakers volumio[19557]: SPOTIFY: {"status":"play","service":"spop","title":"Memories (feat. Kid Cudi)","artist":"David Guetta, Kid Cudi","album":"One More Love","albumart":"https://i.scdn.co/image/ab67616d00001e02f45c50e7cff5f2376c1e36ea","uri":"spotify:track:5p3SJ3CYqrmFbboAtfNo5n","trackType":"spotify","seek":1000,"duration":210,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Oct 13 23:47:14 bedroom-speakers volumio[19557]: info: CoreCommandRouter::servicePushState Oct 13 23:47:14 bedroom-speakers volumio[19557]: info: CoreStateMachine::pushState Oct 13 23:47:14 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioPushState Oct 13 23:47:14 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:14.984-06:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" state=STATUS_PLAYING positionMs=1000 volume=24 Oct 13 23:47:14 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:14.984-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" id=spotify:track:5p3SJ3CYqrmFbboAtfNo5n title="Memories (feat. Kid Cudi)" Oct 13 23:47:14 bedroom-speakers volumio[19557]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Oct 13 23:47:14 bedroom-speakers volumio[19557]: SPOTIFY: SPOTIFY VOLUME 23 Oct 13 23:47:14 bedroom-speakers volumio[19557]: SPOTIFY: VOLUMIO VOLUME 24 Oct 13 23:47:14 bedroom-speakers volumio[19557]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 23:47:18 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:18.601-06:00 level=INFO msg="player skip next request" component=server type=REQUEST_TYPE_PLAYER_SKIP_NEXT peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" latency=49.884696ms timeout=10s Oct 13 23:47:18 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioNext Oct 13 23:47:18 bedroom-speakers volumio[19557]: info: CoreStateMachine::next Oct 13 23:47:18 bedroom-speakers volumio[19557]: info: Spotify next Oct 13 23:47:18 bedroom-speakers volumio[19557]: info: Sending Spotify command to local API: /player/next Oct 13 23:47:18 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:18-06:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:1RHSvLRpiWLSfmDM3HeU4C" Oct 13 23:47:18 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:18-06:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 23:47:18 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:18-06:00" level=trace msg="emitting websocket event: will_play" Oct 13 23:47:18 bedroom-speakers volumio[19557]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:playlist:37i9dQZF1F5p3rmiWPIYgZ","uri":"spotify:track:1RHSvLRpiWLSfmDM3HeU4C","play_origin":"playlist"}} Oct 13 23:47:18 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:18-06:00" level=debug msg="selected format OGG_VORBIS_320 (9885e66746b0ea431d6e5da4f72952dfed6ad3d2)" uri="spotify:track:1RHSvLRpiWLSfmDM3HeU4C" Oct 13 23:47:18 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:18-06:00" level=debug msg="requested aes key for file 9885e66746b0ea431d6e5da4f72952dfed6ad3d2, gid: 1RHSvLRpiWLSfmDM3HeU4C" Oct 13 23:47:19 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:19-06:00" level=trace msg="found 2 cdn urls" uri="spotify:track:1RHSvLRpiWLSfmDM3HeU4C" Oct 13 23:47:19 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:19-06:00" level=debug msg="fetched first chunk of 12, total size is 6070564 bytes" uri="spotify:track:1RHSvLRpiWLSfmDM3HeU4C" Oct 13 23:47:19 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:19-06:00" level=info msg="loaded track \"Smile\" (paused: false, position: 0ms, duration: 139890ms, prefetched: false)" uri="spotify:track:1RHSvLRpiWLSfmDM3HeU4C" Oct 13 23:47:19 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:19-06:00" level=debug msg="fetched chunk 1/11, size: 524288" uri="spotify:track:1RHSvLRpiWLSfmDM3HeU4C" Oct 13 23:47:19 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:19-06:00" level=debug msg="fetched chunk 2/11, size: 524288" uri="spotify:track:1RHSvLRpiWLSfmDM3HeU4C" Oct 13 23:47:19 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:19-06:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 23:47:19 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:19-06:00" level=trace msg="scheduling prefetch in 110s" Oct 13 23:47:19 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:19-06:00" level=trace msg="emitting websocket event: metadata" Oct 13 23:47:19 bedroom-speakers volumio[19557]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1RHSvLRpiWLSfmDM3HeU4C","name":"Smile","artist_names":["Oliver Tree"],"album_name":"Alone In A Crowd","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0297aa7586b7633e103aceb8ba","position":0,"duration":139890,"release_date":"year:2023 month:9 day:29","track_number":6,"disc_number":1}} Oct 13 23:47:19 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:19-06:00" level=debug msg="fetched chunk 3/11, size: 524288" uri="spotify:track:1RHSvLRpiWLSfmDM3HeU4C" Oct 13 23:47:19 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:19-06:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 23:47:19 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:19-06:00" level=trace msg="emitting websocket event: playing" Oct 13 23:47:19 bedroom-speakers volumio[19557]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:playlist:37i9dQZF1F5p3rmiWPIYgZ","uri":"spotify:track:1RHSvLRpiWLSfmDM3HeU4C","resume":false,"play_origin":"playlist"}} Oct 13 23:47:19 bedroom-speakers volumio[19557]: SPOTIFY: PUSH STATE SPOTIFY Oct 13 23:47:19 bedroom-speakers volumio[19557]: SPOTIFY: {"status":"play","service":"spop","title":"Smile","artist":"Oliver Tree","album":"Alone In A Crowd","albumart":"https://i.scdn.co/image/ab67616d00001e0297aa7586b7633e103aceb8ba","uri":"spotify:track:1RHSvLRpiWLSfmDM3HeU4C","trackType":"spotify","seek":0,"duration":139,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Oct 13 23:47:19 bedroom-speakers volumio[19557]: info: CoreCommandRouter::servicePushState Oct 13 23:47:19 bedroom-speakers volumio[19557]: info: CoreStateMachine::pushState Oct 13 23:47:19 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 23:47:19 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioPushState Oct 13 23:47:19 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:19.418-06:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" state=STATUS_PLAYING positionMs=0 volume=24 Oct 13 23:47:19 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:19.418-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" id=spotify:track:1RHSvLRpiWLSfmDM3HeU4C title=Smile Oct 13 23:47:19 bedroom-speakers volumio[19557]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Oct 13 23:47:19 bedroom-speakers volumio[19557]: SPOTIFY: SPOTIFY VOLUME 23 Oct 13 23:47:19 bedroom-speakers volumio[19557]: SPOTIFY: VOLUMIO VOLUME 24 Oct 13 23:47:19 bedroom-speakers volumio[19557]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 23:47:19 bedroom-speakers volumio[19557]: SPOTIFY: PUSH STATE SPOTIFY Oct 13 23:47:19 bedroom-speakers volumio[19557]: SPOTIFY: {"status":"play","service":"spop","title":"Smile","artist":"Oliver Tree","album":"Alone In A Crowd","albumart":"https://i.scdn.co/image/ab67616d00001e0297aa7586b7633e103aceb8ba","uri":"spotify:track:1RHSvLRpiWLSfmDM3HeU4C","trackType":"spotify","seek":0,"duration":139,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Oct 13 23:47:19 bedroom-speakers volumio[19557]: info: CoreCommandRouter::servicePushState Oct 13 23:47:19 bedroom-speakers volumio[19557]: info: CoreStateMachine::pushState Oct 13 23:47:19 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioPushState Oct 13 23:47:19 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:19.719-06:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" state=STATUS_PLAYING positionMs=0 volume=24 Oct 13 23:47:19 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:19.719-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" id=spotify:track:1RHSvLRpiWLSfmDM3HeU4C title=Smile Oct 13 23:47:19 bedroom-speakers volumio[19557]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Oct 13 23:47:19 bedroom-speakers volumio[19557]: SPOTIFY: SPOTIFY VOLUME 23 Oct 13 23:47:19 bedroom-speakers volumio[19557]: SPOTIFY: VOLUMIO VOLUME 24 Oct 13 23:47:19 bedroom-speakers volumio[19557]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 23:47:22 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:22.135-06:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" latency=45.79692ms timeout=10s Oct 13 23:47:22 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:22.307-06:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" latency=45.79692ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=171.157941ms Oct 13 23:47:22 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:22.353-06:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" latency=45.79692ms timeout=10s endpoint=https://securetoken.googleapis.com duration=216.087538ms Oct 13 23:47:22 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:22.402-06:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" latency=45.79692ms timeout=10s endpoint=https://functions.volumio.cloud duration=264.767238ms Oct 13 23:47:22 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:22.411-06:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" latency=45.79692ms timeout=10s endpoint=https://www.googleapis.com duration=274.34633ms Oct 13 23:47:22 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:22.434-06:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" latency=45.79692ms timeout=10s endpoint=https://functions.volumio.cloud duration=297.470988ms Oct 13 23:47:22 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:22.459-06:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" latency=45.79692ms timeout=10s endpoint=https://database.volumio.cloud duration=322.641383ms Oct 13 23:47:22 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:22.468-06:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" latency=45.79692ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=331.373718ms Oct 13 23:47:22 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:22.476-06:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" latency=45.79692ms timeout=10s endpoint=https://google.com duration=340.212515ms Oct 13 23:47:22 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 13 23:47:22 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 13 23:47:22 bedroom-speakers volumio[19557]: info: Discovery: Getting this device information Oct 13 23:47:22 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioGetState Oct 13 23:47:22 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 13 23:47:22 bedroom-speakers volumio[19557]: verbose: New Socket.io Connection to 192.168.1.94:3000 from 192.168.1.67 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 11 Oct 13 23:47:22 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:22.509-06:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" latency=45.79692ms timeout=10s endpoint=http://pushupdates.volumio.org duration=373.225857ms Oct 13 23:47:22 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 13 23:47:22 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 13 23:47:22 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:22.605-06:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" latency=45.79692ms timeout=10s endpoint=http://plugins.volumio.org duration=468.461522ms Oct 13 23:47:22 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:22.635-06:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" latency=45.79692ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=499.087998ms Oct 13 23:47:22 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:22.695-06:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" latency=45.79692ms timeout=10s endpoint=http://cddb.volumio.org duration=558.334475ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 13 23:47:22 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:47:22.714-06:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" latency=45.79692ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=578.616768ms Oct 13 23:47:26 bedroom-speakers volumio[19557]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 13 23:47:26 bedroom-speakers volumio[19557]: info: FusionDsp - Reload response: {"Reload":{"result":"Ok"}} Oct 13 23:47:27 bedroom-speakers volumio[19557]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 23:47:27 bedroom-speakers volumio[19557]: info: CoreCommandRouter::Close All Modals sent Oct 13 23:47:30 bedroom-speakers volumio[19557]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 13 23:47:30 bedroom-speakers volumio[19557]: info: FusionDsp - Reload response: {"Reload":{"result":"Ok"}} Oct 13 23:47:31 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:31-06:00" level=debug msg="fetched chunk 4/11, size: 524288" uri="spotify:track:1RHSvLRpiWLSfmDM3HeU4C" Oct 13 23:47:31 bedroom-speakers volumio[19557]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 23:47:31 bedroom-speakers volumio[19557]: info: CoreCommandRouter::Close All Modals sent Oct 13 23:47:31 bedroom-speakers volumio[19557]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 13 23:47:31 bedroom-speakers volumio[19557]: info: FusionDsp - Reload response: {"Reload":{"result":"Ok"}} Oct 13 23:47:32 bedroom-speakers volumio[19557]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 23:47:32 bedroom-speakers volumio[19557]: info: CoreCommandRouter::Close All Modals sent Oct 13 23:47:34 bedroom-speakers volumio[19557]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 13 23:47:34 bedroom-speakers volumio[19557]: info: FusionDsp - Reload response: {"Reload":{"result":"Ok"}} Oct 13 23:47:34 bedroom-speakers volumio[19557]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 23:47:34 bedroom-speakers volumio[19557]: info: CoreCommandRouter::Close All Modals sent Oct 13 23:47:35 bedroom-speakers volumio[19557]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 13 23:47:35 bedroom-speakers volumio[19557]: info: FusionDsp - Reload response: {"Reload":{"result":"Ok"}} Oct 13 23:47:35 bedroom-speakers volumio[19557]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 23:47:35 bedroom-speakers volumio[19557]: info: CoreCommandRouter::Close All Modals sent Oct 13 23:47:37 bedroom-speakers volumio[19557]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 13 23:47:37 bedroom-speakers volumio[19557]: info: FusionDsp - Reload response: {"Reload":{"result":"Ok"}} Oct 13 23:47:38 bedroom-speakers volumio[19557]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 23:47:38 bedroom-speakers volumio[19557]: info: CoreCommandRouter::Close All Modals sent Oct 13 23:47:39 bedroom-speakers volumio[19557]: verbose: New Socket.io Connection to 192.168.1.94 from 192.168.1.67 UA: Mozilla/5.0 (Linux; Android 17; SM-S731W Build/CP2A.260605.016; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/153.0.8010.36 Mobile Safari/537.36 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 11 Oct 13 23:47:39 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 13 23:47:39 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioGetVisibleSources Oct 13 23:47:39 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 13 23:47:39 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioGetState Oct 13 23:47:39 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 13 23:47:39 bedroom-speakers volumio[19557]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 23:47:39 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 13 23:47:39 bedroom-speakers volumio[19557]: info: Received Get System Info Oct 13 23:47:39 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 13 23:47:39 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 13 23:47:39 bedroom-speakers volumio[19557]: info: Discovery: Getting this device information Oct 13 23:47:39 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioGetState Oct 13 23:47:39 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 13 23:47:39 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioGetState Oct 13 23:47:39 bedroom-speakers volumio[19557]: info: Listing playlists Oct 13 23:47:39 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 13 23:47:39 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 13 23:47:39 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 13 23:47:39 bedroom-speakers volumio[19557]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 23:47:41 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 13 23:47:41 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:41-06:00" level=trace msg="received accesspoint ping" Oct 13 23:47:41 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:41-06:00" level=trace msg="received accesspoint pong ack" Oct 13 23:47:41 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 13 23:47:41 bedroom-speakers volumio[19557]: info: Received Get System Info Oct 13 23:47:41 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 13 23:47:41 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 13 23:47:41 bedroom-speakers volumio[19557]: info: Discovery: Getting this device information Oct 13 23:47:41 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioGetState Oct 13 23:47:41 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 13 23:47:41 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:41-06:00" level=trace msg="sent dealer ping" Oct 13 23:47:41 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:41-06:00" level=trace msg="received dealer pong" Oct 13 23:47:42 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 13 23:47:42 bedroom-speakers volumio[19557]: info: Received Get System Info Oct 13 23:47:42 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 13 23:47:42 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 13 23:47:42 bedroom-speakers volumio[19557]: info: Discovery: Getting this device information Oct 13 23:47:42 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioGetState Oct 13 23:47:42 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 13 23:47:43 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:43-06:00" level=debug msg="fetched chunk 5/11, size: 524288" uri="spotify:track:1RHSvLRpiWLSfmDM3HeU4C" Oct 13 23:47:44 bedroom-speakers volumio[19557]: info: CALLMETHOD: audio_interface fusiondsp disableeffect Oct 13 23:47:44 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: fusiondsp , disableeffect Oct 13 23:47:44 bedroom-speakers volumio[19557]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 13 23:47:44 bedroom-speakers volumio[19557]: info: FusionDsp - Effects disabled Oct 13 23:47:44 bedroom-speakers volumio[19557]: info: FusionDsp - Reload response: {"Reload":{"result":"Ok"}} Oct 13 23:47:44 bedroom-speakers volumio[19557]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 23:47:44 bedroom-speakers volumio[19557]: info: CoreCommandRouter::Close All Modals sent Oct 13 23:47:52 bedroom-speakers volumio[19557]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 13 23:47:52 bedroom-speakers volumio[19557]: info: FusionDsp - Effects disabled Oct 13 23:47:52 bedroom-speakers volumio[19557]: info: FusionDsp - Reload response: {"Reload":{"result":"Ok"}} Oct 13 23:47:52 bedroom-speakers volumio[19557]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 23:47:52 bedroom-speakers volumio[19557]: info: CoreCommandRouter::Close All Modals sent Oct 13 23:47:54 bedroom-speakers volumio[19557]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 13 23:47:54 bedroom-speakers volumio[19557]: info: FusionDsp - Effects disabled Oct 13 23:47:54 bedroom-speakers volumio[19557]: info: FusionDsp - Reload response: {"Reload":{"result":"Ok"}} Oct 13 23:47:54 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:47:54-06:00" level=debug msg="fetched chunk 6/11, size: 524288" uri="spotify:track:1RHSvLRpiWLSfmDM3HeU4C" Oct 13 23:47:54 bedroom-speakers volumio[19557]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 23:47:54 bedroom-speakers volumio[19557]: info: CoreCommandRouter::Close All Modals sent Oct 13 23:47:55 bedroom-speakers volumio[19557]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 13 23:47:55 bedroom-speakers volumio[19557]: info: FusionDsp - Effects disabled Oct 13 23:47:55 bedroom-speakers volumio[19557]: info: FusionDsp - Reload response: {"Reload":{"result":"Ok"}} Oct 13 23:47:55 bedroom-speakers volumio[19557]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 23:47:55 bedroom-speakers volumio[19557]: info: CoreCommandRouter::Close All Modals sent Oct 13 23:47:56 bedroom-speakers volumio[19557]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 13 23:47:56 bedroom-speakers volumio[19557]: info: FusionDsp - Effects disabled Oct 13 23:47:56 bedroom-speakers volumio[19557]: info: FusionDsp - Reload response: {"Reload":{"result":"Ok"}} Oct 13 23:47:56 bedroom-speakers volumio[19557]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 23:47:56 bedroom-speakers volumio[19557]: info: CoreCommandRouter::Close All Modals sent Oct 13 23:47:59 bedroom-speakers volumio[19557]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 13 23:47:59 bedroom-speakers volumio[19557]: info: FusionDsp - Effects disabled Oct 13 23:47:59 bedroom-speakers volumio[19557]: info: FusionDsp - Reload response: {"Reload":{"result":"Ok"}} Oct 13 23:47:59 bedroom-speakers volumio[19557]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 23:47:59 bedroom-speakers volumio[19557]: info: CoreCommandRouter::Close All Modals sent Oct 13 23:48:00 bedroom-speakers volumio[19557]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 13 23:48:00 bedroom-speakers volumio[19557]: info: FusionDsp - Effects disabled Oct 13 23:48:00 bedroom-speakers volumio[19557]: info: FusionDsp - Reload response: {"Reload":{"result":"Ok"}} Oct 13 23:48:00 bedroom-speakers volumio[19557]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 23:48:00 bedroom-speakers volumio[19557]: info: CoreCommandRouter::Close All Modals sent Oct 13 23:48:01 bedroom-speakers volumio[19557]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 13 23:48:01 bedroom-speakers volumio[19557]: info: FusionDsp - Effects disabled Oct 13 23:48:01 bedroom-speakers volumio[19557]: info: FusionDsp - Reload response: {"Reload":{"result":"Ok"}} Oct 13 23:48:01 bedroom-speakers volumio[19557]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 23:48:01 bedroom-speakers volumio[19557]: info: CoreCommandRouter::Close All Modals sent Oct 13 23:48:02 bedroom-speakers volumio[19557]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 13 23:48:02 bedroom-speakers volumio[19557]: info: FusionDsp - Effects disabled Oct 13 23:48:02 bedroom-speakers volumio[19557]: info: FusionDsp - Reload response: {"Reload":{"result":"Ok"}} Oct 13 23:48:02 bedroom-speakers volumio[19557]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 23:48:02 bedroom-speakers volumio[19557]: info: CoreCommandRouter::Close All Modals sent Oct 13 23:48:02 bedroom-speakers volumio[19557]: verbose: New Socket.io Connection to 192.168.1.94 from 192.168.1.67 UA: Mozilla/5.0 (Linux; Android 17; SM-S731W Build/CP2A.260605.016; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/153.0.8010.36 Mobile Safari/537.36 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 11 Oct 13 23:48:03 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 13 23:48:03 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioGetVisibleSources Oct 13 23:48:03 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 13 23:48:03 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioGetState Oct 13 23:48:03 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 13 23:48:03 bedroom-speakers volumio[19557]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 23:48:03 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 13 23:48:03 bedroom-speakers volumio[19557]: info: Received Get System Info Oct 13 23:48:03 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 13 23:48:03 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 13 23:48:03 bedroom-speakers volumio[19557]: info: Discovery: Getting this device information Oct 13 23:48:03 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioGetState Oct 13 23:48:03 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 13 23:48:03 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioGetState Oct 13 23:48:03 bedroom-speakers volumio[19557]: info: Listing playlists Oct 13 23:48:03 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 13 23:48:03 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 13 23:48:03 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 13 23:48:03 bedroom-speakers volumio[19557]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 23:48:04 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 13 23:48:04 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 13 23:48:04 bedroom-speakers volumio[19557]: info: Received Get System Info Oct 13 23:48:04 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 13 23:48:04 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 13 23:48:04 bedroom-speakers volumio[19557]: info: Discovery: Getting this device information Oct 13 23:48:04 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioGetState Oct 13 23:48:04 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 13 23:48:05 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 13 23:48:05 bedroom-speakers volumio[19557]: info: Received Get System Info Oct 13 23:48:05 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 13 23:48:05 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 13 23:48:05 bedroom-speakers volumio[19557]: info: Discovery: Getting this device information Oct 13 23:48:05 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioGetState Oct 13 23:48:05 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 13 23:48:06 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:48:06-06:00" level=debug msg="fetched chunk 7/11, size: 524288" uri="spotify:track:1RHSvLRpiWLSfmDM3HeU4C" Oct 13 23:48:11 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:48:11-06:00" level=trace msg="sent dealer ping" Oct 13 23:48:11 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:48:11-06:00" level=trace msg="received dealer pong" Oct 13 23:48:12 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 13 23:48:18 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:48:18-06:00" level=debug msg="fetched chunk 8/11, size: 524288" uri="spotify:track:1RHSvLRpiWLSfmDM3HeU4C" Oct 13 23:48:21 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 13 23:48:21 bedroom-speakers volumio[19557]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Oct 13 23:48:21 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Oct 13 23:48:21 bedroom-speakers volumio[19557]: info: Received Get System Version Oct 13 23:48:21 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 13 23:48:21 bedroom-speakers volumio[19557]: info: Received Get System Info Oct 13 23:48:21 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 13 23:48:21 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 13 23:48:21 bedroom-speakers volumio[19557]: info: Discovery: Getting this device information Oct 13 23:48:21 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioGetState Oct 13 23:48:21 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 13 23:48:22 bedroom-speakers volumio[19557]: info: CALLMETHOD: audio_interface fusiondsp choosedsp [object Object] Oct 13 23:48:22 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: fusiondsp , choosedsp Oct 13 23:48:22 bedroom-speakers volumio[19557]: info: FusionDsp - PEQ graph server stopped Oct 13 23:48:22 bedroom-speakers volumio[19557]: info: FusionDsp - Stoping PEQ Graph server for PEQ or EQ15 or 2XEQ15 Oct 13 23:48:22 bedroom-speakers volumio[19557]: info: FusionDsp - Selected DSP type is : EQ3 Oct 13 23:48:23 bedroom-speakers volumio[19557]: info: FusionDsp - Chunksise set to 256 Oct 13 23:48:23 bedroom-speakers volumio[19557]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 23:48:23 bedroom-speakers volumio[19557]: info: CoreCommandRouter::Close All Modals sent Oct 13 23:48:23 bedroom-speakers volumio[19557]: info: CALLMETHOD: audio_interface fusiondsp choosedsp [object Object] Oct 13 23:48:23 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: fusiondsp , choosedsp Oct 13 23:48:23 bedroom-speakers volumio[19557]: info: FusionDsp - Stoping PEQ Graph server for PEQ or EQ15 or 2XEQ15 Oct 13 23:48:23 bedroom-speakers volumio[19557]: info: FusionDsp - Selected DSP type is : EQ3 Oct 13 23:48:23 bedroom-speakers volumio[19557]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 13 23:48:23 bedroom-speakers volumio[19557]: info: FusionDsp - Reload response: {"Reload":{"result":"Ok"}} Oct 13 23:48:23 bedroom-speakers volumio[19557]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 23:48:23 bedroom-speakers volumio[19557]: info: CoreCommandRouter::Close All Modals sent Oct 13 23:48:23 bedroom-speakers volumio[19557]: info: FusionDsp - Chunksise set to 256 Oct 13 23:48:23 bedroom-speakers volumio[19557]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 23:48:23 bedroom-speakers volumio[19557]: info: CoreCommandRouter::Close All Modals sent Oct 13 23:48:24 bedroom-speakers volumio[19557]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 13 23:48:24 bedroom-speakers volumio[19557]: info: FusionDsp - Reload response: {"Reload":{"result":"Ok"}} Oct 13 23:48:24 bedroom-speakers volumio[19557]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 23:48:24 bedroom-speakers volumio[19557]: info: CoreCommandRouter::Close All Modals sent Oct 13 23:48:30 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:48:30-06:00" level=debug msg="fetched chunk 9/11, size: 524288" uri="spotify:track:1RHSvLRpiWLSfmDM3HeU4C" Oct 13 23:48:35 bedroom-speakers volumio[19557]: info: CALLMETHOD: audio_interface fusiondsp disableeffect Oct 13 23:48:35 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: fusiondsp , disableeffect Oct 13 23:48:36 bedroom-speakers volumio[19557]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 13 23:48:36 bedroom-speakers volumio[19557]: info: FusionDsp - Effects disabled Oct 13 23:48:36 bedroom-speakers volumio[19557]: info: FusionDsp - Reload response: {"Reload":{"result":"Ok"}} Oct 13 23:48:36 bedroom-speakers volumio[19557]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 23:48:36 bedroom-speakers volumio[19557]: info: CoreCommandRouter::Close All Modals sent Oct 13 23:48:36 bedroom-speakers volumio[19557]: info: CALLMETHOD: audio_interface fusiondsp disableeffect Oct 13 23:48:36 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: fusiondsp , disableeffect Oct 13 23:48:37 bedroom-speakers volumio[19557]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 13 23:48:37 bedroom-speakers volumio[19557]: info: FusionDsp - Effects disabled Oct 13 23:48:37 bedroom-speakers volumio[19557]: info: FusionDsp - Reload response: {"Reload":{"result":"Ok"}} Oct 13 23:48:37 bedroom-speakers volumio[19557]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 23:48:37 bedroom-speakers volumio[19557]: info: CoreCommandRouter::Close All Modals sent Oct 13 23:48:37 bedroom-speakers volumio[19557]: info: CALLMETHOD: audio_interface fusiondsp enableeffect Oct 13 23:48:37 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: fusiondsp , enableeffect Oct 13 23:48:37 bedroom-speakers volumio[19557]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 13 23:48:37 bedroom-speakers volumio[19557]: info: FusionDsp - Reload response: {"Reload":{"result":"Ok"}} Oct 13 23:48:38 bedroom-speakers volumio[19557]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 23:48:38 bedroom-speakers volumio[19557]: info: CoreCommandRouter::Close All Modals sent Oct 13 23:48:41 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:48:41-06:00" level=trace msg="sent dealer ping" Oct 13 23:48:41 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:48:41-06:00" level=trace msg="received dealer pong" Oct 13 23:48:42 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:48:42-06:00" level=debug msg="fetched chunk 10/11, size: 524288" uri="spotify:track:1RHSvLRpiWLSfmDM3HeU4C" Oct 13 23:48:46 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 13 23:48:46 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 13 23:48:46 bedroom-speakers volumio[19557]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Starting Uninstall of plugin audio_interface - fusiondsp Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Uninstalling plugin fusiondsp Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: FusionDsp - Stopping clipped samples monitor Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: FusionDsp - Clipped samples monitor stopped Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: FusionDsp - Stopping FusionDsp service Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: camilladsp service terminated, instance 3 Oct 13 23:48:50 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:48:50.145-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Disabling plugin fusiondsp Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Preparing to generate the ALSA configuration file Oct 13 23:48:50 bedroom-speakers sudo[28414]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop fusiondsp.service Oct 13 23:48:50 bedroom-speakers sudo[28414]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioPause Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: CoreStateMachine::pause Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: CoreStateMachine::stPlaybackTimer Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: CoreStateMachine::servicePause Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: CoreCommandRouter::servicePause Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Spotify Received pause Oct 13 23:48:50 bedroom-speakers volumio[19557]: SPOTIFY: SPOTIFY PAUSE Oct 13 23:48:50 bedroom-speakers volumio[19557]: SPOTIFY: {"status":"play","title":"Smile","artist":"Oliver Tree","album":"Alone In A Crowd","albumart":"https://i.scdn.co/image/ab67616d00001e0297aa7586b7633e103aceb8ba","uri":"spotify:track:1RHSvLRpiWLSfmDM3HeU4C","trackType":"spotify","codec":"ogg","seek":0,"duration":139,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":24,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"volatile":true,"service":"spop"} Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Sending Spotify command to local API: /player/pause Oct 13 23:48:50 bedroom-speakers systemd[1]: Stopping fusiondsp.service - FusionDsp Daemon... Oct 13 23:48:50 bedroom-speakers volumio[27409]: ======== Running on http://0.0.0.0:5011 ======== Oct 13 23:48:50 bedroom-speakers volumio[27409]: (Press CTRL+C to quit) Oct 13 23:48:50 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:48:50-06:00" level=debug msg="pause track at 91053ms" Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Asound.conf file written Oct 13 23:48:50 bedroom-speakers sudo[28418]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Oct 13 23:48:50 bedroom-speakers sudo[28418]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 13 23:48:50 bedroom-speakers sudo[28418]: pam_unix(sudo:session): session closed for user root Oct 13 23:48:50 bedroom-speakers volumio[19557]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Oct 13 23:48:50 bedroom-speakers volumio[19557]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Oct 13 23:48:50 bedroom-speakers volumio[19557]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Output device has changed, restarting MPD Oct 13 23:48:50 bedroom-speakers sudo[28426]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 13 23:48:50 bedroom-speakers sudo[28426]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 13 23:48:50 bedroom-speakers sudo[28426]: pam_unix(sudo:session): session closed for user root Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Output device has changed, restarting Shairport Sync Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 13 23:48:50 bedroom-speakers sudo[28429]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 13 23:48:50 bedroom-speakers sudo[28429]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 13 23:48:50 bedroom-speakers systemd[1]: Stopping mpd.service - Music Player Daemon... Oct 13 23:48:50 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:48:50.244-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Checking if uninstall.sh is present Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Executing uninstall.sh Oct 13 23:48:50 bedroom-speakers systemd[1]: mpd.service: Deactivated successfully. Oct 13 23:48:50 bedroom-speakers systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 13 23:48:50 bedroom-speakers systemd[1]: mpd.socket: Deactivated successfully. Oct 13 23:48:50 bedroom-speakers systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 13 23:48:50 bedroom-speakers systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: MPD Permissions set Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioGetState Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 23:48:50 bedroom-speakers sudo[28438]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/audio_interface/fusiondsp/uninstall.sh Oct 13 23:48:50 bedroom-speakers sudo[28438]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Starting Shairport Sync Oct 13 23:48:50 bedroom-speakers systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 13 23:48:50 bedroom-speakers systemd[1]: Starting mpd.service - Music Player Daemon... Oct 13 23:48:50 bedroom-speakers systemd[1]: fusiondsp.service: Deactivated successfully. Oct 13 23:48:50 bedroom-speakers systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Oct 13 23:48:50 bedroom-speakers sudo[28414]: pam_unix(sudo:session): session closed for user root Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: FusionDsp - Reporting Fusion DSP Disabled Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Removing fusiondspeq DSP Signal Path Element Oct 13 23:48:50 bedroom-speakers sudo[28451]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 13 23:48:50 bedroom-speakers sudo[28451]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 13 23:48:50 bedroom-speakers sudo[28453]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/rm /etc/systemd/system/fusiondsp.service Oct 13 23:48:50 bedroom-speakers sudo[28453]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 13 23:48:50 bedroom-speakers sudo[28453]: pam_unix(sudo:session): session closed for user root Oct 13 23:48:50 bedroom-speakers systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 13 23:48:50 bedroom-speakers sudo[28451]: pam_unix(sudo:session): session closed for user root Oct 13 23:48:50 bedroom-speakers sudo[28455]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/systemctl daemon-reload Oct 13 23:48:50 bedroom-speakers sudo[28455]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 13 23:48:50 bedroom-speakers sudo[28450]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 13 23:48:50 bedroom-speakers sudo[28450]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Shairport-Sync Started Oct 13 23:48:50 bedroom-speakers sudo[28450]: pam_unix(sudo:session): session closed for user root Oct 13 23:48:50 bedroom-speakers systemd[1]: Reloading. Oct 13 23:48:50 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:48:50-06:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 23:48:50 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:48:50-06:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 23:48:50 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:48:50-06:00" level=trace msg="emitting websocket event: paused" Oct 13 23:48:50 bedroom-speakers volumio[19557]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:playlist:37i9dQZF1F5p3rmiWPIYgZ","uri":"spotify:track:1RHSvLRpiWLSfmDM3HeU4C","play_origin":"playlist"}} Oct 13 23:48:50 bedroom-speakers volumio[19557]: SPOTIFY: PUSH STATE SPOTIFY Oct 13 23:48:50 bedroom-speakers volumio[19557]: SPOTIFY: {"status":"pause","service":"spop","title":"Smile","artist":"Oliver Tree","album":"Alone In A Crowd","albumart":"https://i.scdn.co/image/ab67616d00001e0297aa7586b7633e103aceb8ba","uri":"spotify:track:1RHSvLRpiWLSfmDM3HeU4C","trackType":"spotify","seek":91000,"duration":139,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: CoreCommandRouter::servicePushState Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: CoreStateMachine::pushState Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioPushState Oct 13 23:48:50 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:48:50.463-06:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" state=STATUS_PAUSED positionMs=91000 volume=24 Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: FusionDsp - Volumio is not playing Oct 13 23:48:50 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:48:50.466-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" id=spotify:track:1RHSvLRpiWLSfmDM3HeU4C title=Smile Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: FusionDsp - Clipped samples monitor stopped Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: FusionDsp - Volumio is not playing Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: FusionDsp - Clipped samples monitor stopped Oct 13 23:48:50 bedroom-speakers volumio[19557]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Oct 13 23:48:50 bedroom-speakers volumio[19557]: SPOTIFY: SPOTIFY VOLUME 23 Oct 13 23:48:50 bedroom-speakers volumio[19557]: SPOTIFY: VOLUMIO VOLUME 24 Oct 13 23:48:50 bedroom-speakers volumio[19557]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: camilladsp respawn in 100 ms (attempt 1/10) Oct 13 23:48:50 bedroom-speakers 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. Oct 13 23:48:50 bedroom-speakers 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. Oct 13 23:48:50 bedroom-speakers sudo[28455]: pam_unix(sudo:session): session closed for user root Oct 13 23:48:50 bedroom-speakers sudo[28438]: pam_unix(sudo:session): session closed for user root Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Uninstall script completed Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Removing plugin fusiondsp from configuration Oct 13 23:48:50 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:48:50.741-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 13 23:48:50 bedroom-speakers mpd[28459]: 2026-10-13T23:48:50 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 13 23:48:50 bedroom-speakers systemd[1]: Started mpd.service - Music Player Daemon. Oct 13 23:48:50 bedroom-speakers sudo[28429]: pam_unix(sudo:session): session closed for user root Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Successfully removed fusiondsp configuration files Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Plugin folders cleanup Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Scanning into folder /volumio/app/plugins/ Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Scanning category audio_interface Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Scanning category miscellanea Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Scanning category music_service Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Scanning category plugins.json Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Scanning category system_controller Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Scanning category user_interface Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Scanning into folder /data/plugins/ Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Scanning category audio_interface Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Cleaning folder for fusiondsp Oct 13 23:48:50 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:48:50.798-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Scanning category music_service Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Scanning category system_controller Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Scanning category system_hardware Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: Plugin folders cleanup completed Oct 13 23:48:50 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:48:50.916-06:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: [{"prettyName":"Spotify","name":"spop","category":"music_service","version":"4.4.1","icon":"fa-spotify","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"YouTube Cast Receiver","name":"ytcr","category":"music_service","version":"2.2.1","icon":"fa-youtube","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Raspberry Pi EEPROM Firmware Updater","name":"rpi_eeprom_updater","category":"system_controller","version":"1.0.7","icon":"fa-microchip","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Rotary Encoder II","name":"rotaryencoder2","category":"system_hardware","version":"2.1.23","icon":"fa-circle-o-notch","isManuallyInstalled":false,"enabled":true,"active":true}] Oct 13 23:48:50 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 13 23:48:50 bedroom-speakers volumio[19557]: error: updateQueue error: null Oct 13 23:48:54 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:48:54.996-06:00 level=INFO msg="player play request" component=server type=REQUEST_TYPE_PLAYER_PLAY peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" latency=40.462479ms timeout=10s Oct 13 23:48:54 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioPlay Oct 13 23:48:54 bedroom-speakers volumio[19557]: info: CoreStateMachine::play index undefined Oct 13 23:48:54 bedroom-speakers volumio[19557]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 23:48:54 bedroom-speakers volumio[19557]: info: CorePlayQueue::getTrack 2 Oct 13 23:48:54 bedroom-speakers volumio[19557]: info: CoreStateMachine::startPlaybackTimer Oct 13 23:48:54 bedroom-speakers volumio[19557]: info: CorePlayQueue::getTrack 2 Oct 13 23:48:54 bedroom-speakers volumio[19557]: info: Spotify Resume Oct 13 23:48:54 bedroom-speakers volumio[19557]: info: Sending Spotify command to local API: /player/resume Oct 13 23:48:55 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:48:55-06:00" level=trace msg="seek to 91053ms (diff: 37ms, samples: 4015437, bytes: 3990234)" uri="spotify:track:1RHSvLRpiWLSfmDM3HeU4C" Oct 13 23:48:55 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:48:55-06: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" Oct 13 23:48:55 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:48:55-06:00" level=debug msg="resume track at 91016ms" Oct 13 23:48:55 bedroom-speakers volumio[19557]: info: camilladsp respawn in 200 ms (attempt 2/10) Oct 13 23:48:55 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:48:55-06:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 23:48:55 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:48:55-06:00" level=trace msg="scheduling prefetch in 19s" Oct 13 23:48:55 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:48:55-06:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 23:48:55 bedroom-speakers go-librespot[27641]: time="2026-10-13T23:48:55-06:00" level=trace msg="emitting websocket event: playing" Oct 13 23:48:55 bedroom-speakers volumio[19557]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:playlist:37i9dQZF1F5p3rmiWPIYgZ","uri":"spotify:track:1RHSvLRpiWLSfmDM3HeU4C","resume":true,"play_origin":"playlist"}} Oct 13 23:48:55 bedroom-speakers volumio[19557]: SPOTIFY: PUSH STATE SPOTIFY Oct 13 23:48:55 bedroom-speakers volumio[19557]: SPOTIFY: {"status":"play","service":"spop","title":"Smile","artist":"Oliver Tree","album":"Alone In A Crowd","albumart":"https://i.scdn.co/image/ab67616d00001e0297aa7586b7633e103aceb8ba","uri":"spotify:track:1RHSvLRpiWLSfmDM3HeU4C","trackType":"spotify","seek":91000,"duration":139,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Oct 13 23:48:55 bedroom-speakers volumio[19557]: info: CoreCommandRouter::servicePushState Oct 13 23:48:55 bedroom-speakers volumio[19557]: info: CorePlayQueue::getTrack 2 Oct 13 23:48:55 bedroom-speakers volumio[19557]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Smile","artist":"Oliver Tree","album":"Alone In A Crowd","albumart":"https://i.scdn.co/image/ab67616d00001e0297aa7586b7633e103aceb8ba","uri":"spotify:track:1RHSvLRpiWLSfmDM3HeU4C","trackType":"spotify","seek":91000,"duration":139,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Oct 13 23:48:55 bedroom-speakers volumio[19557]: verbose: CURRENT POSITION 2 Oct 13 23:48:55 bedroom-speakers volumio[19557]: info: CoreStateMachine::syncState stateService play Oct 13 23:48:55 bedroom-speakers volumio[19557]: info: CoreStateMachine::syncState currentStatus pause Oct 13 23:48:55 bedroom-speakers volumio[19557]: info: CoreStateMachine::pushState Oct 13 23:48:55 bedroom-speakers volumio[19557]: info: CorePlayQueue::getTrack 2 Oct 13 23:48:55 bedroom-speakers volumio[19557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 23:48:55 bedroom-speakers volumio[19557]: info: CoreCommandRouter::volumioPushState Oct 13 23:48:55 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:48:55.203-06:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" state=STATUS_PLAYING positionMs=195975 volume=24 Oct 13 23:48:55 bedroom-speakers volumio5-onboarding[1606]: time=2026-10-13T23:48:55.204-06:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.67:60920 @ 0x1cc22a0" id=spotify:track:4jQqM4NI79HEcWHUJb8Hvf title="I Wonder" Oct 13 23:48:55 bedroom-speakers volumio[19557]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 13 23:48:55 bedroom-speakers volumio[19557]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 13 23:48:55 bedroom-speakers volumio[19557]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 13 23:48:55 bedroom-speakers volumio[19557]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 13 23:48:55 bedroom-speakers volumio[19557]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 13 23:48:55 bedroom-speakers volumio[19557]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 13 23:48:55 bedroom-speakers volumio[19557]: info: FusionDsp - Volumio is playing Oct 13 23:48:55 bedroom-speakers volumio[19557]: warn: FusionDsp - Monitor WebSocket not open, skipping commands Oct 13 23:48:55 bedroom-speakers volumio[19557]: info: FusionDsp - Volumio is playing Oct 13 23:48:55 bedroom-speakers volumio[19557]: warn: FusionDsp - Monitor WebSocket not open, skipping commands Oct 13 23:48:55 bedroom-speakers volumio[19557]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Oct 13 23:48:55 bedroom-speakers volumio[19557]: SPOTIFY: SPOTIFY VOLUME 23 Oct 13 23:48:55 bedroom-speakers volumio[19557]: SPOTIFY: VOLUMIO VOLUME 24 Oct 13 23:48:55 bedroom-speakers volumio[19557]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 13 23:48:55 bedroom-speakers volumio[19557]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 13 23:48:55 bedroom-speakers volumio[19557]: Error: spawn /data/plugins/audio_interface/fusiondsp/camilladsp ENOENT Oct 13 23:48:55 bedroom-speakers volumio[19557]: at ChildProcess._handle.onexit (node:internal/child_process:286:19) Oct 13 23:48:55 bedroom-speakers volumio[19557]: at onErrorNT (node:internal/child_process:484:16) Oct 13 23:48:55 bedroom-speakers volumio[19557]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Oct 13 23:48:55 bedroom-speakers volumio[19557]: errno: -2, Oct 13 23:48:55 bedroom-speakers volumio[19557]: code: 'ENOENT', Oct 13 23:48:55 bedroom-speakers volumio[19557]: syscall: 'spawn /data/plugins/audio_interface/fusiondsp/camilladsp', Oct 13 23:48:55 bedroom-speakers volumio[19557]: path: '/data/plugins/audio_interface/fusiondsp/camilladsp', Oct 13 23:48:55 bedroom-speakers volumio[19557]: spawnargs: [ Oct 13 23:48:55 bedroom-speakers volumio[19557]: '-p', Oct 13 23:48:55 bedroom-speakers volumio[19557]: 9876, Oct 13 23:48:55 bedroom-speakers volumio[19557]: '-o', Oct 13 23:48:55 bedroom-speakers volumio[19557]: '/tmp/camilladsp.log', Oct 13 23:48:55 bedroom-speakers volumio[19557]: '-l', Oct 13 23:48:55 bedroom-speakers volumio[19557]: 'warn', Oct 13 23:48:55 bedroom-speakers volumio[19557]: '/data/configuration/audio_interface/fusiondsp/camilladsp.yml' Oct 13 23:48:55 bedroom-speakers volumio[19557]: ] Oct 13 23:48:55 bedroom-speakers volumio[19557]: } Oct 13 23:48:55 bedroom-speakers volumio[19557]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 13 23:48:55 bedroom-speakers sudo[28524]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-13 23:47' Oct 13 23:48:55 bedroom-speakers sudo[28524]: 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"