Jun 26 12:30:00 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:30:00.018+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" id= title="Sympathy For The Devil - 50th Anniversary Edition" Jun 26 12:30:01 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:30:01 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:30:02 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 229. Jun 26 12:30:02 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:02 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:02 primo-plus go-librespot[5152]: go-librespot daemon starting... Jun 26 12:30:02 primo-plus go-librespot[5153]: time="2026-06-26T12:30:02+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:30:02 primo-plus go-librespot[5153]: time="2026-06-26T12:30:02+02:00" level=debug msg="app state loaded" Jun 26 12:30:02 primo-plus go-librespot[5153]: time="2026-06-26T12:30:02+02:00" level=debug msg="stored credentials not found" Jun 26 12:30:02 primo-plus go-librespot[5153]: time="2026-06-26T12:30:02+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:30:02 primo-plus go-librespot[5153]: time="2026-06-26T12:30:02+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:30:02 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:30:02 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:30:03 primo-plus volumio[1285]: info: CoreCommandRouter::servicePushState Jun 26 12:30:03 primo-plus volumio[1285]: info: CoreStateMachine::pushState Jun 26 12:30:03 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 26 12:30:03 primo-plus volumio[1285]: info: CoreCommandRouter::volumioPushState Jun 26 12:30:03 primo-plus volumio[1285]: info: CoreCommandRouter::volumioGetState Jun 26 12:30:03 primo-plus volumio[1285]: info: MRS: Pushing multiroomSync output update for this device Jun 26 12:30:03 primo-plus volumio[1285]: info: MRS: Pushing multiroomSync output Jun 26 12:30:03 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:30:03.091+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" state=STATUS_PLAYING positionMs=0 volume=40 Jun 26 12:30:03 primo-plus volumio[1285]: info: Signalling Playback active due to playback status change Jun 26 12:30:03 primo-plus volumio[1285]: info: Updating RAAT Signal Path Jun 26 12:30:03 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: Received new metadata for 9C:73:B1:3B:D7:DA Jun 26 12:30:03 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: [metaCache] Saved metadata to /tmp/bluetooth-cache/meta-9C:73:B1:3B:D7:DA.json Jun 26 12:30:03 primo-plus volumio[1285]: info: CoreCommandRouter::servicePushState Jun 26 12:30:03 primo-plus volumio[1285]: info: CoreStateMachine::pushState Jun 26 12:30:03 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 26 12:30:03 primo-plus volumio[1285]: info: CoreCommandRouter::volumioPushState Jun 26 12:30:03 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:30:03.137+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" id= title="Sympathy For The Devil - 50th Anniversary Edition" Jun 26 12:30:03 primo-plus volumio[1285]: info: CoreCommandRouter::volumioGetState Jun 26 12:30:03 primo-plus volumio[1285]: info: MRS: Pushing multiroomSync output update for this device Jun 26 12:30:03 primo-plus volumio[1285]: info: MRS: Pushing multiroomSync output Jun 26 12:30:03 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:30:03.144+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" state=STATUS_PLAYING positionMs=0 volume=40 Jun 26 12:30:03 primo-plus volumio[1285]: An internal error occurred while serving an albumart. Details: NotFoundError: Not Found Jun 26 12:30:03 primo-plus volumio[1285]: at createHttpError (/volumio/node_modules/send/index.js:979:12) Jun 26 12:30:03 primo-plus volumio[1285]: at SendStream.error (/volumio/node_modules/send/index.js:270:31) Jun 26 12:30:03 primo-plus volumio[1285]: at SendStream.pipe (/volumio/node_modules/send/index.js:580:14) Jun 26 12:30:03 primo-plus volumio[1285]: at sendfile (/volumio/node_modules/express/lib/response.js:1139:8) Jun 26 12:30:03 primo-plus volumio[1285]: at ServerResponse.sendFile (/volumio/node_modules/express/lib/response.js:450:3) Jun 26 12:30:03 primo-plus volumio[1285]: at Promise._failFn (/volumio/app/plugins/miscellanea/albumart/albumart.js:449:13) Jun 26 12:30:03 primo-plus volumio[1285]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jun 26 12:30:03 primo-plus volumio[1285]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Jun 26 12:30:03 primo-plus volumio[1285]: info: Signalling Playback active due to playback status change Jun 26 12:30:03 primo-plus volumio[1285]: info: Updating RAAT Signal Path Jun 26 12:30:03 primo-plus volumio[1285]: info: CoreCommandRouter::servicePushState Jun 26 12:30:03 primo-plus volumio[1285]: info: CoreStateMachine::pushState Jun 26 12:30:03 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 26 12:30:03 primo-plus volumio[1285]: info: CoreCommandRouter::volumioPushState Jun 26 12:30:03 primo-plus volumio[1285]: info: CoreCommandRouter::volumioGetState Jun 26 12:30:03 primo-plus volumio[1285]: info: MRS: Pushing multiroomSync output update for this device Jun 26 12:30:03 primo-plus volumio[1285]: info: MRS: Pushing multiroomSync output Jun 26 12:30:03 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:30:03.175+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" state=STATUS_PLAYING positionMs=0 volume=40 Jun 26 12:30:03 primo-plus volumio[1285]: info: Signalling Playback active due to playback status change Jun 26 12:30:03 primo-plus volumio[1285]: info: Updating RAAT Signal Path Jun 26 12:30:03 primo-plus volumio[1285]: An internal error occurred while serving an albumart. Details: NotFoundError: Not Found Jun 26 12:30:03 primo-plus volumio[1285]: at createHttpError (/volumio/node_modules/send/index.js:979:12) Jun 26 12:30:03 primo-plus volumio[1285]: at SendStream.error (/volumio/node_modules/send/index.js:270:31) Jun 26 12:30:03 primo-plus volumio[1285]: at SendStream.pipe (/volumio/node_modules/send/index.js:580:14) Jun 26 12:30:03 primo-plus volumio[1285]: at sendfile (/volumio/node_modules/express/lib/response.js:1139:8) Jun 26 12:30:03 primo-plus volumio[1285]: at ServerResponse.sendFile (/volumio/node_modules/express/lib/response.js:450:3) Jun 26 12:30:03 primo-plus volumio[1285]: at Promise._failFn (/volumio/app/plugins/miscellanea/albumart/albumart.js:449:13) Jun 26 12:30:03 primo-plus volumio[1285]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jun 26 12:30:03 primo-plus volumio[1285]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Jun 26 12:30:03 primo-plus volumio[1285]: An internal error occurred while serving an albumart. Details: NotFoundError: Not Found Jun 26 12:30:03 primo-plus volumio[1285]: at createHttpError (/volumio/node_modules/send/index.js:979:12) Jun 26 12:30:03 primo-plus volumio[1285]: at SendStream.error (/volumio/node_modules/send/index.js:270:31) Jun 26 12:30:03 primo-plus volumio[1285]: at SendStream.pipe (/volumio/node_modules/send/index.js:580:14) Jun 26 12:30:03 primo-plus volumio[1285]: at sendfile (/volumio/node_modules/express/lib/response.js:1139:8) Jun 26 12:30:03 primo-plus volumio[1285]: at ServerResponse.sendFile (/volumio/node_modules/express/lib/response.js:450:3) Jun 26 12:30:03 primo-plus volumio[1285]: at Promise._failFn (/volumio/app/plugins/miscellanea/albumart/albumart.js:449:13) Jun 26 12:30:03 primo-plus volumio[1285]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jun 26 12:30:03 primo-plus volumio[1285]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Jun 26 12:30:03 primo-plus volumio[1285]: info: CoreCommandRouter::servicePushState Jun 26 12:30:03 primo-plus volumio[1285]: info: CoreStateMachine::pushState Jun 26 12:30:03 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 26 12:30:03 primo-plus volumio[1285]: info: CoreCommandRouter::volumioPushState Jun 26 12:30:03 primo-plus volumio[1285]: info: CoreCommandRouter::volumioGetState Jun 26 12:30:03 primo-plus volumio[1285]: info: MRS: Pushing multiroomSync output update for this device Jun 26 12:30:03 primo-plus volumio[1285]: info: MRS: Pushing multiroomSync output Jun 26 12:30:03 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:30:03.495+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" state=STATUS_PLAYING positionMs=182 volume=40 Jun 26 12:30:03 primo-plus volumio[1285]: info: Signalling Playback active due to playback status change Jun 26 12:30:03 primo-plus volumio[1285]: info: Updating RAAT Signal Path Jun 26 12:30:03 primo-plus volumio[1285]: An internal error occurred while serving an albumart. Details: NotFoundError: Not Found Jun 26 12:30:03 primo-plus volumio[1285]: at createHttpError (/volumio/node_modules/send/index.js:979:12) Jun 26 12:30:03 primo-plus volumio[1285]: at SendStream.error (/volumio/node_modules/send/index.js:270:31) Jun 26 12:30:03 primo-plus volumio[1285]: at SendStream.pipe (/volumio/node_modules/send/index.js:580:14) Jun 26 12:30:03 primo-plus volumio[1285]: at sendfile (/volumio/node_modules/express/lib/response.js:1139:8) Jun 26 12:30:03 primo-plus volumio[1285]: at ServerResponse.sendFile (/volumio/node_modules/express/lib/response.js:450:3) Jun 26 12:30:03 primo-plus volumio[1285]: at Promise._failFn (/volumio/app/plugins/miscellanea/albumart/albumart.js:449:13) Jun 26 12:30:03 primo-plus volumio[1285]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jun 26 12:30:03 primo-plus volumio[1285]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Jun 26 12:30:03 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:30:03.586+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" id= title="Beast Of Burden - Remastered 1994" Jun 26 12:30:03 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:30:03.649+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" id= title="Beast Of Burden - Remastered 1994" Jun 26 12:30:03 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:30:03.707+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" id= title="Beast Of Burden - Remastered 1994" Jun 26 12:30:04 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:30:04 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:30:05 primo-plus volumio[1285]: info: Executing endpoint metavolumio Jun 26 12:30:05 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 26 12:30:05 primo-plus volumio[1285]: info: Executing endpoint metavolumio Jun 26 12:30:05 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 26 12:30:05 primo-plus volumio[1285]: info: Executing endpoint metavolumio Jun 26 12:30:05 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 26 12:30:05 primo-plus volumio[1285]: error: Failed request for metavolumio API Jun 26 12:30:05 primo-plus volumio[1285]: error: Failed request for metavolumio API Jun 26 12:30:05 primo-plus volumio[1285]: error: Failed request for metavolumio API Jun 26 12:30:05 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 230. Jun 26 12:30:05 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:05 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:05 primo-plus go-librespot[5173]: go-librespot daemon starting... Jun 26 12:30:05 primo-plus go-librespot[5174]: time="2026-06-26T12:30:05+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:30:05 primo-plus go-librespot[5174]: time="2026-06-26T12:30:05+02:00" level=debug msg="app state loaded" Jun 26 12:30:05 primo-plus go-librespot[5174]: time="2026-06-26T12:30:05+02:00" level=debug msg="stored credentials not found" Jun 26 12:30:05 primo-plus go-librespot[5174]: time="2026-06-26T12:30:05+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:30:05 primo-plus go-librespot[5174]: time="2026-06-26T12:30:05+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:30:05 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:30:05 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:30:07 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:30:07 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:30:08 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 231. Jun 26 12:30:08 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:08 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:08 primo-plus go-librespot[5180]: go-librespot daemon starting... Jun 26 12:30:08 primo-plus go-librespot[5181]: time="2026-06-26T12:30:08+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:30:08 primo-plus go-librespot[5181]: time="2026-06-26T12:30:08+02:00" level=debug msg="app state loaded" Jun 26 12:30:08 primo-plus go-librespot[5181]: time="2026-06-26T12:30:08+02:00" level=debug msg="stored credentials not found" Jun 26 12:30:08 primo-plus go-librespot[5181]: time="2026-06-26T12:30:08+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:30:08 primo-plus go-librespot[5181]: time="2026-06-26T12:30:08+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:30:08 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:30:08 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:30:10 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:30:10 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:30:11 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 232. Jun 26 12:30:11 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:11 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:12 primo-plus go-librespot[5187]: go-librespot daemon starting... Jun 26 12:30:12 primo-plus go-librespot[5188]: time="2026-06-26T12:30:12+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:30:12 primo-plus go-librespot[5188]: time="2026-06-26T12:30:12+02:00" level=debug msg="app state loaded" Jun 26 12:30:12 primo-plus go-librespot[5188]: time="2026-06-26T12:30:12+02:00" level=debug msg="stored credentials not found" Jun 26 12:30:12 primo-plus go-librespot[5188]: time="2026-06-26T12:30:12+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:30:12 primo-plus go-librespot[5188]: time="2026-06-26T12:30:12+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:30:12 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:30:12 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:30:13 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:30:13 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:30:14 primo-plus volumio[1285]: info: CoreCommandRouter::servicePushState Jun 26 12:30:14 primo-plus volumio[1285]: info: CoreStateMachine::pushState Jun 26 12:30:14 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 26 12:30:14 primo-plus volumio[1285]: info: CoreCommandRouter::volumioPushState Jun 26 12:30:14 primo-plus volumio[1285]: info: CoreCommandRouter::volumioGetState Jun 26 12:30:14 primo-plus volumio[1285]: info: MRS: Pushing multiroomSync output update for this device Jun 26 12:30:14 primo-plus volumio[1285]: info: MRS: Pushing multiroomSync output Jun 26 12:30:14 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:30:14.856+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" state=STATUS_PLAYING positionMs=69385 volume=40 Jun 26 12:30:14 primo-plus volumio[1285]: info: Signalling Playback active due to playback status change Jun 26 12:30:14 primo-plus volumio[1285]: info: Updating RAAT Signal Path Jun 26 12:30:14 primo-plus volumio[1285]: An internal error occurred while serving an albumart. Details: NotFoundError: Not Found Jun 26 12:30:14 primo-plus volumio[1285]: at createHttpError (/volumio/node_modules/send/index.js:979:12) Jun 26 12:30:14 primo-plus volumio[1285]: at SendStream.error (/volumio/node_modules/send/index.js:270:31) Jun 26 12:30:14 primo-plus volumio[1285]: at SendStream.pipe (/volumio/node_modules/send/index.js:580:14) Jun 26 12:30:14 primo-plus volumio[1285]: at sendfile (/volumio/node_modules/express/lib/response.js:1139:8) Jun 26 12:30:14 primo-plus volumio[1285]: at ServerResponse.sendFile (/volumio/node_modules/express/lib/response.js:450:3) Jun 26 12:30:14 primo-plus volumio[1285]: at Promise._failFn (/volumio/app/plugins/miscellanea/albumart/albumart.js:449:13) Jun 26 12:30:14 primo-plus volumio[1285]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jun 26 12:30:14 primo-plus volumio[1285]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Jun 26 12:30:14 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:30:14.897+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" id= title="Beast Of Burden - Remastered 1994" Jun 26 12:30:15 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 233. Jun 26 12:30:15 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:15 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:15 primo-plus go-librespot[5205]: go-librespot daemon starting... Jun 26 12:30:15 primo-plus go-librespot[5211]: time="2026-06-26T12:30:15+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:30:15 primo-plus go-librespot[5211]: time="2026-06-26T12:30:15+02:00" level=debug msg="app state loaded" Jun 26 12:30:15 primo-plus go-librespot[5211]: time="2026-06-26T12:30:15+02:00" level=debug msg="stored credentials not found" Jun 26 12:30:15 primo-plus go-librespot[5211]: time="2026-06-26T12:30:15+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:30:15 primo-plus go-librespot[5211]: time="2026-06-26T12:30:15+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:30:15 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:30:15 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:30:16 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:30:16 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:30:18 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 234. Jun 26 12:30:18 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:18 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:18 primo-plus go-librespot[5217]: go-librespot daemon starting... Jun 26 12:30:18 primo-plus go-librespot[5218]: time="2026-06-26T12:30:18+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:30:18 primo-plus go-librespot[5218]: time="2026-06-26T12:30:18+02:00" level=debug msg="app state loaded" Jun 26 12:30:18 primo-plus go-librespot[5218]: time="2026-06-26T12:30:18+02:00" level=debug msg="stored credentials not found" Jun 26 12:30:18 primo-plus go-librespot[5218]: time="2026-06-26T12:30:18+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:30:18 primo-plus go-librespot[5218]: time="2026-06-26T12:30:18+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:30:18 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:30:18 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:30:19 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:30:19 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:30:21 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 235. Jun 26 12:30:21 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:21 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:21 primo-plus go-librespot[5224]: go-librespot daemon starting... Jun 26 12:30:21 primo-plus go-librespot[5225]: time="2026-06-26T12:30:21+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:30:21 primo-plus go-librespot[5225]: time="2026-06-26T12:30:21+02:00" level=debug msg="app state loaded" Jun 26 12:30:21 primo-plus go-librespot[5225]: time="2026-06-26T12:30:21+02:00" level=debug msg="stored credentials not found" Jun 26 12:30:21 primo-plus go-librespot[5225]: time="2026-06-26T12:30:21+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:30:21 primo-plus go-librespot[5225]: time="2026-06-26T12:30:21+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:30:21 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:30:21 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:30:22 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:30:22 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:30:24 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 236. Jun 26 12:30:24 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:24 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:24 primo-plus go-librespot[5231]: go-librespot daemon starting... Jun 26 12:30:25 primo-plus go-librespot[5232]: time="2026-06-26T12:30:25+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:30:25 primo-plus go-librespot[5232]: time="2026-06-26T12:30:25+02:00" level=debug msg="app state loaded" Jun 26 12:30:25 primo-plus go-librespot[5232]: time="2026-06-26T12:30:25+02:00" level=debug msg="stored credentials not found" Jun 26 12:30:25 primo-plus go-librespot[5232]: time="2026-06-26T12:30:25+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:30:25 primo-plus go-librespot[5232]: time="2026-06-26T12:30:25+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:30:25 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:30:25 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:30:25 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:30:25 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:30:28 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:30:28 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:30:28 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 237. Jun 26 12:30:28 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:28 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:28 primo-plus go-librespot[5253]: go-librespot daemon starting... Jun 26 12:30:28 primo-plus go-librespot[5254]: time="2026-06-26T12:30:28+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:30:28 primo-plus go-librespot[5254]: time="2026-06-26T12:30:28+02:00" level=debug msg="app state loaded" Jun 26 12:30:28 primo-plus go-librespot[5254]: time="2026-06-26T12:30:28+02:00" level=debug msg="stored credentials not found" Jun 26 12:30:28 primo-plus go-librespot[5254]: time="2026-06-26T12:30:28+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:30:28 primo-plus go-librespot[5254]: time="2026-06-26T12:30:28+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:30:28 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:30:28 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:30:31 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:30:31 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:30:31 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 238. Jun 26 12:30:31 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:31 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:31 primo-plus go-librespot[5261]: go-librespot daemon starting... Jun 26 12:30:31 primo-plus go-librespot[5262]: time="2026-06-26T12:30:31+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:30:31 primo-plus go-librespot[5262]: time="2026-06-26T12:30:31+02:00" level=debug msg="app state loaded" Jun 26 12:30:31 primo-plus go-librespot[5262]: time="2026-06-26T12:30:31+02:00" level=debug msg="stored credentials not found" Jun 26 12:30:31 primo-plus go-librespot[5262]: time="2026-06-26T12:30:31+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:30:31 primo-plus go-librespot[5262]: time="2026-06-26T12:30:31+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:30:31 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:30:31 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:30:34 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:30:34 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:30:34 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 239. Jun 26 12:30:34 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:34 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:34 primo-plus go-librespot[5269]: go-librespot daemon starting... Jun 26 12:30:34 primo-plus go-librespot[5270]: time="2026-06-26T12:30:34+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:30:34 primo-plus go-librespot[5270]: time="2026-06-26T12:30:34+02:00" level=debug msg="app state loaded" Jun 26 12:30:34 primo-plus go-librespot[5270]: time="2026-06-26T12:30:34+02:00" level=debug msg="stored credentials not found" Jun 26 12:30:34 primo-plus go-librespot[5270]: time="2026-06-26T12:30:34+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:30:34 primo-plus go-librespot[5270]: time="2026-06-26T12:30:34+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:30:34 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:30:34 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:30:37 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:30:37 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:30:37 primo-plus volumio[1285]: info: CoreCommandRouter::servicePushState Jun 26 12:30:37 primo-plus volumio[1285]: info: CoreStateMachine::pushState Jun 26 12:30:37 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 26 12:30:37 primo-plus volumio[1285]: info: CoreCommandRouter::volumioPushState Jun 26 12:30:37 primo-plus volumio[1285]: info: CoreCommandRouter::volumioGetState Jun 26 12:30:37 primo-plus volumio[1285]: info: MRS: Pushing multiroomSync output update for this device Jun 26 12:30:37 primo-plus volumio[1285]: info: MRS: Pushing multiroomSync output Jun 26 12:30:37 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:30:37.850+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" state=STATUS_PLAYING positionMs=92346 volume=40 Jun 26 12:30:37 primo-plus volumio[1285]: info: CoreCommandRouter::servicePushState Jun 26 12:30:37 primo-plus volumio[1285]: info: CoreStateMachine::pushState Jun 26 12:30:37 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 26 12:30:37 primo-plus volumio[1285]: info: CoreCommandRouter::volumioPushState Jun 26 12:30:37 primo-plus volumio[1285]: info: CoreCommandRouter::volumioGetState Jun 26 12:30:37 primo-plus volumio[1285]: info: MRS: Pushing multiroomSync output update for this device Jun 26 12:30:37 primo-plus volumio[1285]: info: MRS: Pushing multiroomSync output Jun 26 12:30:37 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:30:37.872+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" state=STATUS_PLAYING positionMs=92346 volume=40 Jun 26 12:30:37 primo-plus volumio[1285]: info: Signalling Playback active due to playback status change Jun 26 12:30:37 primo-plus volumio[1285]: info: Signalling Playback active due to playback status change Jun 26 12:30:37 primo-plus volumio[1285]: info: Updating RAAT Signal Path Jun 26 12:30:37 primo-plus volumio[1285]: info: Updating RAAT Signal Path Jun 26 12:30:37 primo-plus volumio[1285]: An internal error occurred while serving an albumart. Details: NotFoundError: Not Found Jun 26 12:30:37 primo-plus volumio[1285]: at createHttpError (/volumio/node_modules/send/index.js:979:12) Jun 26 12:30:37 primo-plus volumio[1285]: at SendStream.error (/volumio/node_modules/send/index.js:270:31) Jun 26 12:30:37 primo-plus volumio[1285]: at SendStream.pipe (/volumio/node_modules/send/index.js:580:14) Jun 26 12:30:37 primo-plus volumio[1285]: at sendfile (/volumio/node_modules/express/lib/response.js:1139:8) Jun 26 12:30:37 primo-plus volumio[1285]: at ServerResponse.sendFile (/volumio/node_modules/express/lib/response.js:450:3) Jun 26 12:30:37 primo-plus volumio[1285]: at Promise._failFn (/volumio/app/plugins/miscellanea/albumart/albumart.js:449:13) Jun 26 12:30:37 primo-plus volumio[1285]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jun 26 12:30:37 primo-plus volumio[1285]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Jun 26 12:30:37 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:30:37.909+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" id= title="Beast Of Burden - Remastered 1994" Jun 26 12:30:37 primo-plus volumio[1285]: An internal error occurred while serving an albumart. Details: NotFoundError: Not Found Jun 26 12:30:37 primo-plus volumio[1285]: at createHttpError (/volumio/node_modules/send/index.js:979:12) Jun 26 12:30:37 primo-plus volumio[1285]: at SendStream.error (/volumio/node_modules/send/index.js:270:31) Jun 26 12:30:37 primo-plus volumio[1285]: at SendStream.pipe (/volumio/node_modules/send/index.js:580:14) Jun 26 12:30:37 primo-plus volumio[1285]: at sendfile (/volumio/node_modules/express/lib/response.js:1139:8) Jun 26 12:30:37 primo-plus volumio[1285]: at ServerResponse.sendFile (/volumio/node_modules/express/lib/response.js:450:3) Jun 26 12:30:37 primo-plus volumio[1285]: at Promise._failFn (/volumio/app/plugins/miscellanea/albumart/albumart.js:449:13) Jun 26 12:30:37 primo-plus volumio[1285]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jun 26 12:30:37 primo-plus volumio[1285]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Jun 26 12:30:37 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 240. Jun 26 12:30:37 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:37 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:30:37.966+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" id= title="Beast Of Burden - Remastered 1994" Jun 26 12:30:37 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:37 primo-plus go-librespot[5290]: go-librespot daemon starting... Jun 26 12:30:38 primo-plus go-librespot[5291]: time="2026-06-26T12:30:38+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:30:38 primo-plus go-librespot[5291]: time="2026-06-26T12:30:38+02:00" level=debug msg="app state loaded" Jun 26 12:30:38 primo-plus go-librespot[5291]: time="2026-06-26T12:30:38+02:00" level=debug msg="stored credentials not found" Jun 26 12:30:38 primo-plus go-librespot[5291]: time="2026-06-26T12:30:38+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:30:38 primo-plus go-librespot[5291]: time="2026-06-26T12:30:38+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:30:38 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:30:38 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:30:38 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: Debounce: emitting confirmed playback=false for 9C:73:B1:3B:D7:DA (player.Status=paused, after 800ms) Jun 26 12:30:38 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: [dbus-next] Playback state changed: false from 9C:73:B1:3B:D7:DA Jun 26 12:30:38 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: Received pause signal from winner, scheduling idle check Jun 26 12:30:38 primo-plus volumio[1285]: info: CoreCommandRouter::servicePushState Jun 26 12:30:38 primo-plus volumio[1285]: info: CoreStateMachine::pushState Jun 26 12:30:38 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 26 12:30:38 primo-plus volumio[1285]: info: CoreCommandRouter::volumioPushState Jun 26 12:30:38 primo-plus volumio[1285]: info: CoreCommandRouter::volumioGetState Jun 26 12:30:38 primo-plus volumio[1285]: info: MRS: Pushing multiroomSync output update for this device Jun 26 12:30:38 primo-plus volumio[1285]: info: MRS: Pushing multiroomSync output Jun 26 12:30:38 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:30:38.739+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" state=STATUS_PAUSED positionMs=92346 volume=40 Jun 26 12:30:38 primo-plus volumio[1285]: info: Updating RAAT Signal Path Jun 26 12:30:38 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:30:38.808+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" id= title="Beast Of Burden - Remastered 1994" Jun 26 12:30:38 primo-plus volumio[1285]: info: MCU Signalled Playback Inactive Jun 26 12:30:39 primo-plus bluealsa[903]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093/char0094/desc0096, ...) Jun 26 12:30:39 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: setWinningMac: none Jun 26 12:30:39 primo-plus volumio[1285]: [106B blob data] Jun 26 12:30:39 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: [FUNC] detachBluetooth Jun 26 12:30:39 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: [FUNC] btAudioOutput Jun 26 12:30:39 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: [dbus-next] Disabling Bluetooth Audio Output Jun 26 12:30:39 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: Killing bluealsa-aplay process Jun 26 12:30:39 primo-plus bluealsa[903]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093/char0094, ...) Jun 26 12:30:39 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: Bluetooth audio output disabled. Jun 26 12:30:39 primo-plus volumio[1285]: verbose: UNSET VOLATILE: Service: bluetooth Jun 26 12:30:39 primo-plus volumio[1285]: info: CoreStateMachine::resetVolumioState Jun 26 12:30:39 primo-plus volumio[1285]: info: CoreStateMachine::getcurrentVolume Jun 26 12:30:39 primo-plus volumio[1285]: info: CoreCommandRouter::volumioRetrievevolume Jun 26 12:30:39 primo-plus bluealsa[903]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093/char0097/desc0099, ...) Jun 26 12:30:39 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: inputs , retrievevolume Jun 26 12:30:39 primo-plus bluealsa[903]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093/char0097, ...) Jun 26 12:30:39 primo-plus bluealsa[903]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093, ...) Jun 26 12:30:39 primo-plus volumio[1285]: info: CoreStateMachine::pushState Jun 26 12:30:39 primo-plus volumio[1285]: info: CorePlayQueue::getTrack 0 Jun 26 12:30:39 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 26 12:30:39 primo-plus bluealsa[903]: ../src/ba-transport-pcm.c:453: Closing PCM: 19 Jun 26 12:30:39 primo-plus volumio[1285]: info: CoreCommandRouter::volumioPushState Jun 26 12:30:39 primo-plus bluealsa[903]: ../src/ba-transport.c:203: PCM clients check keep-alive: 0 ms Jun 26 12:30:39 primo-plus volumio[1285]: info: CoreCommandRouter::volumioGetState Jun 26 12:30:39 primo-plus volumio[1285]: info: CorePlayQueue::getTrack 0 Jun 26 12:30:39 primo-plus volumio[1285]: info: MRS: Pushing multiroomSync output update for this device Jun 26 12:30:39 primo-plus volumio[1285]: info: MRS: Pushing multiroomSync output Jun 26 12:30:39 primo-plus volumio[1285]: info: CoreCommandRouter::volumioStop Jun 26 12:30:39 primo-plus volumio[1285]: info: CoreStateMachine::stop Jun 26 12:30:39 primo-plus volumio[1285]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 26 12:30:39 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:30:39.370+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" state=STATUS_STOPPED positionMs=0 volume=40 Jun 26 12:30:39 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: Detached Bluetooth after transport removal Jun 26 12:30:39 primo-plus bluealsa[903]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service009a/char009b, ...) Jun 26 12:30:39 primo-plus bluealsa[903]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service009a/char009d, ...) Jun 26 12:30:39 primo-plus bluealsa[903]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service009a/char009f, ...) Jun 26 12:30:39 primo-plus bluealsa[903]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service009a, ...) Jun 26 12:30:39 primo-plus volumio[1285]: info: Updating RAAT Signal Path Jun 26 12:30:39 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: bluealsa-aplay exited with code null, signal SIGKILL Jun 26 12:30:39 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:30:39.437+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" id= title= Jun 26 12:30:40 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:30:40 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:30:40 primo-plus bluealsa[903]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093, ...) Jun 26 12:30:40 primo-plus bluealsa[903]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093/char0094, ...) Jun 26 12:30:40 primo-plus bluealsa[903]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093/char0094/desc0096, ...) Jun 26 12:30:40 primo-plus bluealsa[903]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093/char0097, ...) Jun 26 12:30:40 primo-plus bluealsa[903]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093/char0097/desc0099, ...) Jun 26 12:30:40 primo-plus bluealsa[903]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State Jun 26 12:30:40 primo-plus bluealsa[903]: ../src/ba-transport-pcm.c:307: Closing BT socket duplicate [16]: 17 Jun 26 12:30:40 primo-plus bluealsa[903]: ../src/ba-transport.c:381: Closing A2DP transport: 16 Jun 26 12:30:40 primo-plus bluealsa[903]: ../src/ba-transport-pcm.c:257: Exiting IO thread [ba-a2dp-sbc]: A2DP Sink (SBC) Jun 26 12:30:41 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 241. Jun 26 12:30:41 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:41 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:41 primo-plus go-librespot[5308]: go-librespot daemon starting... Jun 26 12:30:41 primo-plus bluealsa[903]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093/char0094/desc0096, ...) Jun 26 12:30:41 primo-plus bluealsa[903]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093/char0094, ...) Jun 26 12:30:41 primo-plus bluealsa[903]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093/char0097/desc0099, ...) Jun 26 12:30:41 primo-plus bluealsa[903]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093/char0097, ...) Jun 26 12:30:41 primo-plus bluealsa[903]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093, ...) Jun 26 12:30:41 primo-plus go-librespot[5309]: time="2026-06-26T12:30:41+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:30:41 primo-plus go-librespot[5309]: time="2026-06-26T12:30:41+02:00" level=debug msg="app state loaded" Jun 26 12:30:41 primo-plus go-librespot[5309]: time="2026-06-26T12:30:41+02:00" level=debug msg="stored credentials not found" Jun 26 12:30:41 primo-plus go-librespot[5309]: time="2026-06-26T12:30:41+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:30:41 primo-plus go-librespot[5309]: time="2026-06-26T12:30:41+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:30:41 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:30:41 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:30:42 primo-plus bluealsa[903]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093, ...) Jun 26 12:30:42 primo-plus bluealsa[903]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093/char0094, ...) Jun 26 12:30:42 primo-plus bluealsa[903]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093/char0094/desc0096, ...) Jun 26 12:30:42 primo-plus bluealsa[903]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093/char0097, ...) Jun 26 12:30:42 primo-plus bluealsa[903]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093/char0097/desc0099, ...) Jun 26 12:30:42 primo-plus bluealsa[903]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service009a, ...) Jun 26 12:30:42 primo-plus bluealsa[903]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service009a/char009b, ...) Jun 26 12:30:42 primo-plus bluealsa[903]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service009a/char009d, ...) Jun 26 12:30:42 primo-plus bluealsa[903]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service009a/char009f, ...) Jun 26 12:30:43 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:30:43 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:30:44 primo-plus bluealsa[903]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093/char0094/desc0096, ...) Jun 26 12:30:44 primo-plus bluealsa[903]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093/char0094, ...) Jun 26 12:30:44 primo-plus bluealsa[903]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093/char0097/desc0099, ...) Jun 26 12:30:44 primo-plus bluealsa[903]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093/char0097, ...) Jun 26 12:30:44 primo-plus bluealsa[903]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093, ...) Jun 26 12:30:44 primo-plus bluealsa[903]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service009a/char009b, ...) Jun 26 12:30:44 primo-plus bluealsa[903]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service009a/char009d, ...) Jun 26 12:30:44 primo-plus bluealsa[903]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service009a/char009f, ...) Jun 26 12:30:44 primo-plus bluealsa[903]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service009a, ...) Jun 26 12:30:44 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 242. Jun 26 12:30:44 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:44 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:44 primo-plus go-librespot[5317]: go-librespot daemon starting... Jun 26 12:30:44 primo-plus go-librespot[5318]: time="2026-06-26T12:30:44+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:30:44 primo-plus go-librespot[5318]: time="2026-06-26T12:30:44+02:00" level=debug msg="app state loaded" Jun 26 12:30:44 primo-plus go-librespot[5318]: time="2026-06-26T12:30:44+02:00" level=debug msg="stored credentials not found" Jun 26 12:30:44 primo-plus go-librespot[5318]: time="2026-06-26T12:30:44+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:30:44 primo-plus go-librespot[5318]: time="2026-06-26T12:30:44+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:30:44 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:30:44 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:30:45 primo-plus bluealsa[903]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093, ...) Jun 26 12:30:45 primo-plus bluealsa[903]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093/char0094, ...) Jun 26 12:30:45 primo-plus bluealsa[903]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093/char0094/desc0096, ...) Jun 26 12:30:45 primo-plus bluealsa[903]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093/char0097, ...) Jun 26 12:30:45 primo-plus bluealsa[903]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_9C_73_B1_3B_D7_DA/service0093/char0097/desc0099, ...) Jun 26 12:30:46 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:30:46 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:30:47 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 243. Jun 26 12:30:47 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:47 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:47 primo-plus go-librespot[5338]: go-librespot daemon starting... Jun 26 12:30:47 primo-plus go-librespot[5339]: time="2026-06-26T12:30:47+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:30:47 primo-plus go-librespot[5339]: time="2026-06-26T12:30:47+02:00" level=debug msg="app state loaded" Jun 26 12:30:47 primo-plus go-librespot[5339]: time="2026-06-26T12:30:47+02:00" level=debug msg="stored credentials not found" Jun 26 12:30:47 primo-plus go-librespot[5339]: time="2026-06-26T12:30:47+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:30:47 primo-plus go-librespot[5339]: time="2026-06-26T12:30:47+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:30:47 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:30:47 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:30:49 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:30:49 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:30:50 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 244. Jun 26 12:30:50 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:50 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:50 primo-plus go-librespot[5345]: go-librespot daemon starting... Jun 26 12:30:51 primo-plus go-librespot[5346]: time="2026-06-26T12:30:51+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:30:51 primo-plus go-librespot[5346]: time="2026-06-26T12:30:51+02:00" level=debug msg="app state loaded" Jun 26 12:30:51 primo-plus go-librespot[5346]: time="2026-06-26T12:30:51+02:00" level=debug msg="stored credentials not found" Jun 26 12:30:51 primo-plus go-librespot[5346]: time="2026-06-26T12:30:51+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:30:51 primo-plus go-librespot[5346]: time="2026-06-26T12:30:51+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:30:51 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:30:51 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:30:52 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:30:52 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:30:54 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 245. Jun 26 12:30:54 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:54 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:54 primo-plus go-librespot[5353]: go-librespot daemon starting... Jun 26 12:30:54 primo-plus go-librespot[5354]: time="2026-06-26T12:30:54+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:30:54 primo-plus go-librespot[5354]: time="2026-06-26T12:30:54+02:00" level=debug msg="app state loaded" Jun 26 12:30:54 primo-plus go-librespot[5354]: time="2026-06-26T12:30:54+02:00" level=debug msg="stored credentials not found" Jun 26 12:30:54 primo-plus go-librespot[5354]: time="2026-06-26T12:30:54+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:30:54 primo-plus go-librespot[5354]: time="2026-06-26T12:30:54+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:30:54 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:30:54 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:30:55 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:30:55 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:30:56 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:30:56.958+02:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="00:00:00:00:00:00%05 @ 0x1efba40" latency=-1541h26m47.251619933s timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_SETUP_V1_INTERNET Jun 26 12:30:57 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:30:57.078+02:00 level=INFO msg="run WiFi scan" component=server type=REQUEST_TYPE_RUN_WIFI_SCAN peer="00:00:00:00:00:00%05 @ 0x1efba40" latency=-1541h26m47.19478484s timeout=1m0s Jun 26 12:30:57 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 246. Jun 26 12:30:57 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:57 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:30:57 primo-plus go-librespot[5374]: go-librespot daemon starting... Jun 26 12:30:57 primo-plus go-librespot[5375]: time="2026-06-26T12:30:57+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:30:57 primo-plus go-librespot[5375]: time="2026-06-26T12:30:57+02:00" level=debug msg="app state loaded" Jun 26 12:30:57 primo-plus go-librespot[5375]: time="2026-06-26T12:30:57+02:00" level=debug msg="stored credentials not found" Jun 26 12:30:57 primo-plus go-librespot[5375]: time="2026-06-26T12:30:57+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:30:57 primo-plus go-librespot[5375]: time="2026-06-26T12:30:57+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:30:57 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:30:57 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:30:58 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:30:58 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:30:59 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:30:59.857+02:00 level=INFO msg="emitting wifi scan event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" networks=11 Jun 26 12:31:00 primo-plus volumio[1285]: info: Received Get System Info Jun 26 12:31:00 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 26 12:31:00 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 26 12:31:00 primo-plus volumio[1285]: info: Discovery: Getting this device information Jun 26 12:31:00 primo-plus volumio[1285]: info: CoreCommandRouter::volumioGetState Jun 26 12:31:00 primo-plus volumio[1285]: info: CorePlayQueue::getTrack 0 Jun 26 12:31:00 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 26 12:31:00 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:31:00.363+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Jun 26 12:31:00 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jun 26 12:31:00 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jun 26 12:31:00 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 247. Jun 26 12:31:00 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:00 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:00 primo-plus go-librespot[5382]: go-librespot daemon starting... Jun 26 12:31:00 primo-plus go-librespot[5383]: time="2026-06-26T12:31:00+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:31:00 primo-plus go-librespot[5383]: time="2026-06-26T12:31:00+02:00" level=debug msg="app state loaded" Jun 26 12:31:00 primo-plus go-librespot[5383]: time="2026-06-26T12:31:00+02:00" level=debug msg="stored credentials not found" Jun 26 12:31:00 primo-plus go-librespot[5383]: time="2026-06-26T12:31:00+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:31:00 primo-plus go-librespot[5383]: time="2026-06-26T12:31:00+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:31:00 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:31:00 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:31:01 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:31:01 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:31:01 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:31:01.226+02:00 level=INFO msg="service successfully established" component=discovery/localnet Jun 26 12:31:03 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 248. Jun 26 12:31:03 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:03 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:03 primo-plus go-librespot[5390]: go-librespot daemon starting... Jun 26 12:31:04 primo-plus go-librespot[5391]: time="2026-06-26T12:31:04+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:31:04 primo-plus go-librespot[5391]: time="2026-06-26T12:31:04+02:00" level=debug msg="app state loaded" Jun 26 12:31:04 primo-plus go-librespot[5391]: time="2026-06-26T12:31:04+02:00" level=debug msg="stored credentials not found" Jun 26 12:31:04 primo-plus go-librespot[5391]: time="2026-06-26T12:31:04+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:31:04 primo-plus go-librespot[5391]: time="2026-06-26T12:31:04+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:31:04 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:31:04 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:31:04 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:31:04 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:31:07 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:31:07 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:31:07 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 249. Jun 26 12:31:07 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:07 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:07 primo-plus go-librespot[5411]: go-librespot daemon starting... Jun 26 12:31:07 primo-plus go-librespot[5412]: time="2026-06-26T12:31:07+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:31:07 primo-plus go-librespot[5412]: time="2026-06-26T12:31:07+02:00" level=debug msg="app state loaded" Jun 26 12:31:07 primo-plus go-librespot[5412]: time="2026-06-26T12:31:07+02:00" level=debug msg="stored credentials not found" Jun 26 12:31:07 primo-plus go-librespot[5412]: time="2026-06-26T12:31:07+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:31:07 primo-plus go-librespot[5412]: time="2026-06-26T12:31:07+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:31:07 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:31:07 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:31:10 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:31:10 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:31:10 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 250. Jun 26 12:31:10 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:10 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:10 primo-plus go-librespot[5418]: go-librespot daemon starting... Jun 26 12:31:10 primo-plus go-librespot[5419]: time="2026-06-26T12:31:10+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:31:10 primo-plus go-librespot[5419]: time="2026-06-26T12:31:10+02:00" level=debug msg="app state loaded" Jun 26 12:31:10 primo-plus go-librespot[5419]: time="2026-06-26T12:31:10+02:00" level=debug msg="stored credentials not found" Jun 26 12:31:10 primo-plus go-librespot[5419]: time="2026-06-26T12:31:10+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:31:10 primo-plus go-librespot[5419]: time="2026-06-26T12:31:10+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:31:10 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:31:10 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:31:13 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:31:13 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:31:13 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 251. Jun 26 12:31:13 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:13 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:13 primo-plus go-librespot[5425]: go-librespot daemon starting... Jun 26 12:31:13 primo-plus go-librespot[5426]: time="2026-06-26T12:31:13+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:31:13 primo-plus go-librespot[5426]: time="2026-06-26T12:31:13+02:00" level=debug msg="app state loaded" Jun 26 12:31:13 primo-plus go-librespot[5426]: time="2026-06-26T12:31:13+02:00" level=debug msg="stored credentials not found" Jun 26 12:31:13 primo-plus go-librespot[5426]: time="2026-06-26T12:31:13+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:31:13 primo-plus go-librespot[5426]: time="2026-06-26T12:31:13+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:31:13 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:31:13 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:31:16 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:31:16 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:31:16 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 252. Jun 26 12:31:16 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:16 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:16 primo-plus go-librespot[5447]: go-librespot daemon starting... Jun 26 12:31:17 primo-plus go-librespot[5448]: time="2026-06-26T12:31:17+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:31:17 primo-plus go-librespot[5448]: time="2026-06-26T12:31:17+02:00" level=debug msg="app state loaded" Jun 26 12:31:17 primo-plus go-librespot[5448]: time="2026-06-26T12:31:17+02:00" level=debug msg="stored credentials not found" Jun 26 12:31:17 primo-plus go-librespot[5448]: time="2026-06-26T12:31:17+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:31:17 primo-plus go-librespot[5448]: time="2026-06-26T12:31:17+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:31:17 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:31:17 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:31:19 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:31:19 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:31:20 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 253. Jun 26 12:31:20 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:20 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:20 primo-plus go-librespot[5454]: go-librespot daemon starting... Jun 26 12:31:20 primo-plus go-librespot[5455]: time="2026-06-26T12:31:20+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:31:20 primo-plus go-librespot[5455]: time="2026-06-26T12:31:20+02:00" level=debug msg="app state loaded" Jun 26 12:31:20 primo-plus go-librespot[5455]: time="2026-06-26T12:31:20+02:00" level=debug msg="stored credentials not found" Jun 26 12:31:20 primo-plus go-librespot[5455]: time="2026-06-26T12:31:20+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:31:20 primo-plus go-librespot[5455]: time="2026-06-26T12:31:20+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:31:20 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:31:20 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:31:22 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:31:22 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:31:23 primo-plus systemd[1]: Starting systemd-tmpfiles-clean.service - Cleanup of Temporary Directories... Jun 26 12:31:23 primo-plus systemd[1]: systemd-tmpfiles-clean.service: Deactivated successfully. Jun 26 12:31:23 primo-plus systemd[1]: Finished systemd-tmpfiles-clean.service - Cleanup of Temporary Directories. Jun 26 12:31:23 primo-plus systemd[1]: run-credentials-systemd\x2dtmpfiles\x2dclean.service.mount: Deactivated successfully. Jun 26 12:31:23 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 254. Jun 26 12:31:23 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:23 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:23 primo-plus go-librespot[5463]: go-librespot daemon starting... Jun 26 12:31:23 primo-plus go-librespot[5464]: time="2026-06-26T12:31:23+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:31:23 primo-plus go-librespot[5464]: time="2026-06-26T12:31:23+02:00" level=debug msg="app state loaded" Jun 26 12:31:23 primo-plus go-librespot[5464]: time="2026-06-26T12:31:23+02:00" level=debug msg="stored credentials not found" Jun 26 12:31:23 primo-plus go-librespot[5464]: time="2026-06-26T12:31:23+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:31:23 primo-plus go-librespot[5464]: time="2026-06-26T12:31:23+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:31:23 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:31:23 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:31:25 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:31:25 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:31:26 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 255. Jun 26 12:31:26 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:26 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:26 primo-plus go-librespot[5484]: go-librespot daemon starting... Jun 26 12:31:26 primo-plus go-librespot[5485]: time="2026-06-26T12:31:26+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:31:26 primo-plus go-librespot[5485]: time="2026-06-26T12:31:26+02:00" level=debug msg="app state loaded" Jun 26 12:31:26 primo-plus go-librespot[5485]: time="2026-06-26T12:31:26+02:00" level=debug msg="stored credentials not found" Jun 26 12:31:26 primo-plus go-librespot[5485]: time="2026-06-26T12:31:26+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:31:26 primo-plus go-librespot[5485]: time="2026-06-26T12:31:26+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:31:26 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:31:26 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:31:28 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:31:28 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:31:29 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 256. Jun 26 12:31:29 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:29 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:29 primo-plus go-librespot[5492]: go-librespot daemon starting... Jun 26 12:31:29 primo-plus go-librespot[5493]: time="2026-06-26T12:31:29+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:31:29 primo-plus go-librespot[5493]: time="2026-06-26T12:31:29+02:00" level=debug msg="app state loaded" Jun 26 12:31:29 primo-plus go-librespot[5493]: time="2026-06-26T12:31:29+02:00" level=debug msg="stored credentials not found" Jun 26 12:31:29 primo-plus go-librespot[5493]: time="2026-06-26T12:31:29+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:31:29 primo-plus go-librespot[5493]: time="2026-06-26T12:31:29+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:31:29 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:31:29 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:31:31 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:31:31 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:31:32 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 257. Jun 26 12:31:32 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:32 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:32 primo-plus go-librespot[5499]: go-librespot daemon starting... Jun 26 12:31:33 primo-plus go-librespot[5500]: time="2026-06-26T12:31:33+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:31:33 primo-plus go-librespot[5500]: time="2026-06-26T12:31:33+02:00" level=debug msg="app state loaded" Jun 26 12:31:33 primo-plus go-librespot[5500]: time="2026-06-26T12:31:33+02:00" level=debug msg="stored credentials not found" Jun 26 12:31:33 primo-plus go-librespot[5500]: time="2026-06-26T12:31:33+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:31:33 primo-plus go-librespot[5500]: time="2026-06-26T12:31:33+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:31:33 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:31:33 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:31:34 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:31:34 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:31:36 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 258. Jun 26 12:31:36 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:36 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:36 primo-plus go-librespot[5521]: go-librespot daemon starting... Jun 26 12:31:36 primo-plus go-librespot[5522]: time="2026-06-26T12:31:36+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:31:36 primo-plus go-librespot[5522]: time="2026-06-26T12:31:36+02:00" level=debug msg="app state loaded" Jun 26 12:31:36 primo-plus go-librespot[5522]: time="2026-06-26T12:31:36+02:00" level=debug msg="stored credentials not found" Jun 26 12:31:36 primo-plus go-librespot[5522]: time="2026-06-26T12:31:36+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:31:36 primo-plus go-librespot[5522]: time="2026-06-26T12:31:36+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:31:36 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:31:36 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:31:37 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:31:37 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:31:39 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 259. Jun 26 12:31:39 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:39 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:39 primo-plus go-librespot[5529]: go-librespot daemon starting... Jun 26 12:31:39 primo-plus go-librespot[5530]: time="2026-06-26T12:31:39+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:31:39 primo-plus go-librespot[5530]: time="2026-06-26T12:31:39+02:00" level=debug msg="app state loaded" Jun 26 12:31:39 primo-plus go-librespot[5530]: time="2026-06-26T12:31:39+02:00" level=debug msg="stored credentials not found" Jun 26 12:31:39 primo-plus go-librespot[5530]: time="2026-06-26T12:31:39+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:31:39 primo-plus go-librespot[5530]: time="2026-06-26T12:31:39+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:31:39 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:31:39 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:31:40 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:31:40 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:31:42 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 260. Jun 26 12:31:42 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:42 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:42 primo-plus go-librespot[5538]: go-librespot daemon starting... Jun 26 12:31:42 primo-plus go-librespot[5539]: time="2026-06-26T12:31:42+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:31:42 primo-plus go-librespot[5539]: time="2026-06-26T12:31:42+02:00" level=debug msg="app state loaded" Jun 26 12:31:42 primo-plus go-librespot[5539]: time="2026-06-26T12:31:42+02:00" level=debug msg="stored credentials not found" Jun 26 12:31:42 primo-plus go-librespot[5539]: time="2026-06-26T12:31:42+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:31:42 primo-plus go-librespot[5539]: time="2026-06-26T12:31:42+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:31:42 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:31:42 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:31:43 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:31:43 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:31:45 primo-plus dhcpcd[774]: eth0: carrier acquired Jun 26 12:31:45 primo-plus kernel: bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx Jun 26 12:31:45 primo-plus dhcpcd[774]: eth0: IAID dd:ea:48:f2 Jun 26 12:31:45 primo-plus dhcpcd[774]: eth0: adding address fe80::5c22:decf:7d74:906b Jun 26 12:31:45 primo-plus dhcpcd[774]: ipv6_addaddr1: Permission denied Jun 26 12:31:45 primo-plus dhcpcd[774]: eth0: soliciting an IPv6 router Jun 26 12:31:45 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 261. Jun 26 12:31:45 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:45 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:45 primo-plus go-librespot[5560]: go-librespot daemon starting... Jun 26 12:31:46 primo-plus go-librespot[5561]: time="2026-06-26T12:31:46+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:31:46 primo-plus go-librespot[5561]: time="2026-06-26T12:31:46+02:00" level=debug msg="app state loaded" Jun 26 12:31:46 primo-plus go-librespot[5561]: time="2026-06-26T12:31:46+02:00" level=debug msg="stored credentials not found" Jun 26 12:31:46 primo-plus go-librespot[5561]: time="2026-06-26T12:31:46+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:31:46 primo-plus go-librespot[5561]: time="2026-06-26T12:31:46+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:31:46 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:31:46 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:31:46 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:31:46 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:31:46 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:31:46.325+02:00 level=INFO msg="emitting ethernet info changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" available=true connected=false macAddress= ip4Address= ip6Address= Jun 26 12:31:46 primo-plus volumio[1285]: info: Received Get System Info Jun 26 12:31:46 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 26 12:31:46 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 26 12:31:46 primo-plus volumio[1285]: info: Discovery: Getting this device information Jun 26 12:31:46 primo-plus volumio[1285]: info: CoreCommandRouter::volumioGetState Jun 26 12:31:46 primo-plus volumio[1285]: info: CorePlayQueue::getTrack 0 Jun 26 12:31:46 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 26 12:31:46 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jun 26 12:31:46 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jun 26 12:31:46 primo-plus ifplugd(eth0)[1013]: Link beat detected. Jun 26 12:31:46 primo-plus ifplugd(eth0)[1013]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Jun 26 12:31:46 primo-plus dhcpcd[774]: eth0: rebinding lease of 10.0.0.223 Jun 26 12:31:46 primo-plus dhcpcd[774]: eth0: probing address 10.0.0.223/8 Jun 26 12:31:46 primo-plus ifplugd(eth0)[1013]: client: sending commands to dhcpcd process Jun 26 12:31:46 primo-plus dhcpcd[774]: control command: dhcpcd eth0 Jun 26 12:31:46 primo-plus dhcpcd[774]: control_free: No such file or directory Jun 26 12:31:47 primo-plus ifplugd(eth0)[1013]: Program executed successfully. Jun 26 12:31:47 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:31:47.299+02:00 level=INFO msg="service successfully established" component=discovery/localnet Jun 26 12:31:47 primo-plus wireless.js[711]: WIRELESS.JS - INFO: === SNM TRANSITION === Jun 26 12:31:47 primo-plus wireless.js[711]: WIRELESS.JS - INFO: Previous ethernet state: disconnected Jun 26 12:31:47 primo-plus wireless.js[711]: WIRELESS.JS - INFO: New ethernet state: connected Jun 26 12:31:47 primo-plus wireless.js[711]: WIRELESS.JS - INFO: Single Network Mode: enabled Jun 26 12:31:47 primo-plus wireless.js[711]: WIRELESS.JS - INFO: First start: no Jun 26 12:31:47 primo-plus wireless.js[711]: WIRELESS.JS - INFO: Action: Switch to ethernet (WiFi scan mode) Jun 26 12:31:47 primo-plus wireless.js[711]: WIRELESS.JS - INFO: === END TRANSITION === Jun 26 12:31:47 primo-plus wireless.js[711]: WIRELESS.JS - INFO: SNM: Ethernet connected, switching to ethernet (WiFi scan mode) Jun 26 12:31:47 primo-plus sudo[5629]: root : PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd -k wlan0 Jun 26 12:31:47 primo-plus sudo[5629]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 26 12:31:47 primo-plus dhcpcd[5630]: dhcpcd not running Jun 26 12:31:47 primo-plus sudo[5629]: pam_unix(sudo:session): session closed for user root Jun 26 12:31:47 primo-plus wireless.js[711]: dhcpcd not running Jun 26 12:31:47 primo-plus wireless.js[711]: WIRELESS.JS - INFO: Wireless.js initializing wireless flow Jun 26 12:31:48 primo-plus systemd[1]: Stopping dnsmasq.service - dnsmasq - A lightweight DHCP and caching DNS server... Jun 26 12:31:48 primo-plus dnsmasq[1431]: exiting on receipt of SIGTERM Jun 26 12:31:48 primo-plus systemd[1]: dnsmasq.service: Deactivated successfully. Jun 26 12:31:48 primo-plus systemd[1]: Stopped dnsmasq.service - dnsmasq - A lightweight DHCP and caching DNS server. Jun 26 12:31:48 primo-plus systemd[1]: Stopping hostapd.service - Access point and authentication server for Wi-Fi and Ethernet... Jun 26 12:31:48 primo-plus systemd[1]: hostapd.service: Deactivated successfully. Jun 26 12:31:48 primo-plus systemd[1]: Stopped hostapd.service - Access point and authentication server for Wi-Fi and Ethernet. Jun 26 12:31:48 primo-plus sudo[5640]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Jun 26 12:31:48 primo-plus sudo[5640]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 26 12:31:48 primo-plus avahi-daemon[692]: Withdrawing address record for 192.168.211.1 on wlan0. Jun 26 12:31:48 primo-plus avahi-daemon[692]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. Jun 26 12:31:48 primo-plus avahi-daemon[692]: Interface wlan0.IPv4 no longer relevant for mDNS. Jun 26 12:31:48 primo-plus sudo[5640]: pam_unix(sudo:session): session closed for user root Jun 26 12:31:48 primo-plus volumio[1285]: info: Discovery: A device disappeared from network Jun 26 12:31:48 primo-plus sudo[5643]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Jun 26 12:31:48 primo-plus sudo[5643]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 26 12:31:48 primo-plus systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Jun 26 12:31:48 primo-plus systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Jun 26 12:31:48 primo-plus systemd[1]: welcome.service: Deactivated successfully. Jun 26 12:31:48 primo-plus systemd[1]: Stopped welcome.service - Show a welcome message on console. Jun 26 12:31:48 primo-plus systemd[1]: Stopping welcome.service - Show a welcome message on console... Jun 26 12:31:48 primo-plus systemd[1]: Starting welcome.service - Show a welcome message on console... Jun 26 12:31:48 primo-plus welcome[5645]: Resolved ip:[0] Jun 26 12:31:48 primo-plus sudo[5643]: pam_unix(sudo:session): session closed for user root Jun 26 12:31:48 primo-plus volumio[1285]: info: Received Get System Info Jun 26 12:31:48 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 26 12:31:48 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 26 12:31:48 primo-plus volumio[1285]: info: Discovery: Getting this device information Jun 26 12:31:48 primo-plus volumio[1285]: info: CoreCommandRouter::volumioGetState Jun 26 12:31:48 primo-plus volumio[1285]: info: CorePlayQueue::getTrack 0 Jun 26 12:31:48 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 26 12:31:48 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:31:48.708+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Jun 26 12:31:48 primo-plus wireless.js[711]: WIRELESS.JS - INFO: Cleaning previous... Jun 26 12:31:48 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jun 26 12:31:48 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jun 26 12:31:48 primo-plus systemd[1]: Finished welcome.service - Show a welcome message on console. Jun 26 12:31:48 primo-plus systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Jun 26 12:31:48 primo-plus sudo[5650]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Jun 26 12:31:48 primo-plus sudo[5650]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 26 12:31:48 primo-plus sudo[5650]: pam_unix(sudo:session): session closed for user root Jun 26 12:31:48 primo-plus kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jun 26 12:31:48 primo-plus wireless.js[711]: WIRELESS.JS - INFO: InterfaceValidator: READY - wlan0 is ready for operations Jun 26 12:31:48 primo-plus wireless.js[711]: WIRELESS.JS - INFO: InterfaceValidator: wlan0 became ready after 1ms Jun 26 12:31:48 primo-plus wireless.js[711]: WIRELESS.JS - INFO: ensureInterfaceReady: Interface ready (MAC: d8:3a:dd:ea:48:f3) Jun 26 12:31:48 primo-plus sudo[5658]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Jun 26 12:31:48 primo-plus sudo[5658]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 26 12:31:48 primo-plus sudo[5658]: pam_unix(sudo:session): session closed for user root Jun 26 12:31:48 primo-plus sudo[5666]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Jun 26 12:31:48 primo-plus sudo[5666]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 26 12:31:49 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 262. Jun 26 12:31:49 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:49 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:31:49 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: AggregateError Jun 26 12:31:49 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:49 primo-plus go-librespot[5670]: go-librespot daemon starting... Jun 26 12:31:49 primo-plus volumio[1285]: info: Received Get System Info Jun 26 12:31:49 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 26 12:31:49 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 26 12:31:49 primo-plus volumio[1285]: info: Discovery: Getting this device information Jun 26 12:31:49 primo-plus volumio[1285]: info: CoreCommandRouter::volumioGetState Jun 26 12:31:49 primo-plus volumio[1285]: info: CorePlayQueue::getTrack 0 Jun 26 12:31:49 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 26 12:31:49 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:31:49.270+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Jun 26 12:31:49 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jun 26 12:31:49 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jun 26 12:31:49 primo-plus go-librespot[5671]: time="2026-06-26T12:31:49+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:31:49 primo-plus go-librespot[5671]: time="2026-06-26T12:31:49+02:00" level=debug msg="app state loaded" Jun 26 12:31:49 primo-plus go-librespot[5671]: time="2026-06-26T12:31:49+02:00" level=debug msg="stored credentials not found" Jun 26 12:31:49 primo-plus go-librespot[5671]: time="2026-06-26T12:31:49+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:31:49 primo-plus go-librespot[5671]: time="2026-06-26T12:31:49+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jun 26 12:31:49 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:31:49 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:31:50 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:31:50.691+02:00 level=INFO msg="service successfully established" component=discovery/localnet Jun 26 12:31:51 primo-plus dhcpcd[774]: eth0: leased 10.0.0.223 for 43200 seconds Jun 26 12:31:51 primo-plus avahi-daemon[692]: Joining mDNS multicast group on interface eth0.IPv4 with address 10.0.0.223. Jun 26 12:31:51 primo-plus avahi-daemon[692]: New relevant interface eth0.IPv4 for mDNS. Jun 26 12:31:51 primo-plus avahi-daemon[692]: Registering new address record for 10.0.0.223 on eth0.IPv4. Jun 26 12:31:51 primo-plus dhcpcd[774]: eth0: adding route to 10.0.0.0/8 Jun 26 12:31:51 primo-plus systemd[1]: welcome.service: Deactivated successfully. Jun 26 12:31:51 primo-plus systemd[1]: Stopped welcome.service - Show a welcome message on console. Jun 26 12:31:51 primo-plus systemd[1]: Stopping welcome.service - Show a welcome message on console... Jun 26 12:31:51 primo-plus dhcpcd[774]: eth0: adding default route via 10.0.0.1 Jun 26 12:31:51 primo-plus systemd[1]: Starting welcome.service - Show a welcome message on console... Jun 26 12:31:51 primo-plus welcome[5693]: Resolved ip:[1] 10.0.0.223 Jun 26 12:31:51 primo-plus systemd[1]: Finished welcome.service - Show a welcome message on console. Jun 26 12:31:51 primo-plus systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Jun 26 12:31:51 primo-plus sudo[5666]: pam_unix(sudo:session): session closed for user root Jun 26 12:31:51 primo-plus wireless.js[711]: WIRELESS.JS - INFO: Regdomain already correct: US Jun 26 12:31:51 primo-plus wireless.js[711]: WIRELESS.JS - INFO: Single Network Mode: Ethernet active, maintaining WiFi scan capability Jun 26 12:31:51 primo-plus wireless.js[711]: WIRELESS.JS - INFO: SNM: Maintaining wlan0 UP without IP (scan mode) Jun 26 12:31:51 primo-plus wireless.js[711]: WIRELESS.JS - INFO: SNM: Users can configure WiFi via WebUI while ethernet is active Jun 26 12:31:51 primo-plus sudo[5711]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Jun 26 12:31:51 primo-plus sudo[5711]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 26 12:31:51 primo-plus sudo[5711]: pam_unix(sudo:session): session closed for user root Jun 26 12:31:51 primo-plus sudo[5714]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Jun 26 12:31:51 primo-plus sudo[5714]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 26 12:31:51 primo-plus sudo[5714]: pam_unix(sudo:session): session closed for user root Jun 26 12:31:51 primo-plus wpa_supplicant[5717]: Successfully initialized wpa_supplicant Jun 26 12:31:51 primo-plus wpa_supplicant[5717]: nl80211: kernel reports: Registration to specific type not supported Jun 26 12:31:51 primo-plus wpa_supplicant[5720]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all Jun 26 12:31:51 primo-plus wireless.js[711]: WIRELESS.JS - INFO: SNM: Transition to scan mode completed in 4186ms Jun 26 12:31:51 primo-plus wireless.js[711]: WIRELESS.JS - INFO: SNM: wlan0 is UP without IP, scan capable Jun 26 12:31:52 primo-plus volumio[1285]: info: Received Get System Info Jun 26 12:31:52 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 26 12:31:52 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 26 12:31:52 primo-plus volumio[1285]: info: Discovery: Getting this device information Jun 26 12:31:52 primo-plus volumio[1285]: info: CoreCommandRouter::volumioGetState Jun 26 12:31:52 primo-plus volumio[1285]: info: CorePlayQueue::getTrack 0 Jun 26 12:31:52 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 26 12:31:52 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:31:52.013+02:00 level=INFO msg="emitting ethernet info changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" available=true connected=true macAddress=d8:3a:dd:ea:48:f2 ip4Address=10.0.0.223/8 ip6Address= Jun 26 12:31:52 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jun 26 12:31:52 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jun 26 12:31:52 primo-plus wireless.js[711]: WIRELESS.JS - INFO: wlan0 state: wpa_state=SCANNING (expected DISCONNECTED or INACTIVE) Jun 26 12:31:52 primo-plus wireless.js[711]: WIRELESS.JS - INFO: Notified systemd about wireless ready Jun 26 12:31:52 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:31:52 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:31:52 primo-plus volumio[1285]: info: Received Get System Info Jun 26 12:31:52 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 26 12:31:52 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 26 12:31:52 primo-plus volumio[1285]: info: Discovery: Getting this device information Jun 26 12:31:52 primo-plus volumio[1285]: info: CoreCommandRouter::volumioGetState Jun 26 12:31:52 primo-plus volumio[1285]: info: CorePlayQueue::getTrack 0 Jun 26 12:31:52 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 26 12:31:52 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jun 26 12:31:52 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jun 26 12:31:52 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:31:52.394+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Jun 26 12:31:52 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 263. Jun 26 12:31:52 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:52 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:52 primo-plus go-librespot[5735]: go-librespot daemon starting... Jun 26 12:31:52 primo-plus go-librespot[5736]: time="2026-06-26T12:31:52+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:31:52 primo-plus go-librespot[5736]: time="2026-06-26T12:31:52+02:00" level=debug msg="app state loaded" Jun 26 12:31:52 primo-plus go-librespot[5736]: time="2026-06-26T12:31:52+02:00" level=debug msg="stored credentials not found" Jun 26 12:31:52 primo-plus go-librespot[5736]: time="2026-06-26T12:31:52+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:31:52 primo-plus volumio[1285]: info: Discovery: adding c9fcdfb8-31ae-4ba0-b78d-bfd7d7259034 Jun 26 12:31:52 primo-plus volumio[1285]: info: Discovery: Found device Primo Plus Jun 26 12:31:52 primo-plus volumio[1285]: info: CoreCommandRouter::volumioGetState Jun 26 12:31:52 primo-plus volumio[1285]: info: CorePlayQueue::getTrack 0 Jun 26 12:31:52 primo-plus go-librespot[5736]: time="2026-06-26T12:31:52+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2026-06-26T12:31:52+02:00 is before 2026-07-09T00:00:00Z" Jun 26 12:31:52 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:31:52 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:31:52 primo-plus ntpd[1005]: IO: Listen normally on 4 eth0 10.0.0.223:123 Jun 26 12:31:52 primo-plus ntpd[1005]: IO: new interface(s) found: waking up resolver Jun 26 12:31:52 primo-plus ntpd[1005]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Jun 26 12:31:52 primo-plus ntpd[1005]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Jun 26 12:31:52 primo-plus ntpd[1005]: DNS: Pool taking: 172.232.208.229 Jun 26 12:31:52 primo-plus ntpd[1005]: DNS: Pool taking: 89.46.74.148 Jun 26 12:31:52 primo-plus ntpd[1005]: DNS: Pool taking: 185.19.184.35 Jun 26 12:31:52 primo-plus ntpd[1005]: DNS: Pool taking: 172.232.209.103 Jun 26 12:31:52 primo-plus ntpd[1005]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Jun 26 12:31:53 primo-plus ntpd[1005]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Jun 26 12:31:53 primo-plus ntpd[1005]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Jun 26 12:31:53 primo-plus ntpd[1005]: DNS: Pool taking: 95.110.135.141 Jun 26 12:31:53 primo-plus ntpd[1005]: DNS: Pool taking: 204.216.214.76 Jun 26 12:31:53 primo-plus ntpd[1005]: DNS: Pool skipping: 185.19.184.35 Jun 26 12:31:53 primo-plus ntpd[1005]: DNS: Pool taking: 217.61.62.224 Jun 26 12:31:53 primo-plus ntpd[1005]: DNS: Pool taking: 2a00:6d41:10:1194::2 Jun 26 12:31:53 primo-plus ntpd[1005]: DNS: Pool taking: 2a06:9801:2f3:100::5 Jun 26 12:31:53 primo-plus ntpd[1005]: DNS: Pool taking: 2a00:6d41:200:2::13 Jun 26 12:31:53 primo-plus ntpd[1005]: DNS: Pool taking: 2a06:e881:7000::d0a:29ac Jun 26 12:31:53 primo-plus ntpd[1005]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Jun 26 12:31:53 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:31:53.998+02:00 level=INFO msg="service successfully established" component=discovery/localnet Jun 26 12:31:54 primo-plus ntpd[1005]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Jun 26 12:31:54 primo-plus ntpd[1005]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Jun 26 12:31:54 primo-plus ntpd[1005]: DNS: Pool taking: 85.199.214.99 Jun 26 12:31:54 primo-plus ntpd[1005]: DNS: Pool taking: 212.45.144.206 Jun 26 12:31:54 primo-plus ntpd[1005]: DNS: Pool skipping: 204.216.214.76 Jun 26 12:31:54 primo-plus ntpd[1005]: DNS: Pool taking: 93.94.88.51 Jun 26 12:31:54 primo-plus ntpd[1005]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Jun 26 12:31:55 primo-plus volumio[1285]: info: Initializing connection to go-librespot Websocket Jun 26 12:31:55 primo-plus volumio[1285]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 26 12:31:55 primo-plus volumio[1285]: info: Received Get System Info Jun 26 12:31:55 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 26 12:31:55 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 26 12:31:55 primo-plus volumio[1285]: info: Discovery: Getting this device information Jun 26 12:31:55 primo-plus volumio[1285]: info: CoreCommandRouter::volumioGetState Jun 26 12:31:55 primo-plus volumio[1285]: info: CorePlayQueue::getTrack 0 Jun 26 12:31:55 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 26 12:31:55 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:31:55.346+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Jun 26 12:31:55 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jun 26 12:31:55 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jun 26 12:31:55 primo-plus volumio[1285]: info: Reporting MCU Network Status: 1 Jun 26 12:31:55 primo-plus volumio[1285]: info: Volumio Network Manager: Network status updated: 1 Jun 26 12:31:55 primo-plus ntpd[1005]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Jun 26 12:31:55 primo-plus systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 264. Jun 26 12:31:55 primo-plus systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:55 primo-plus ntpd[1005]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Jun 26 12:31:55 primo-plus systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jun 26 12:31:55 primo-plus ntpd[1005]: DNS: Pool taking: 185.157.229.254 Jun 26 12:31:55 primo-plus ntpd[1005]: DNS: Pool skipping: 89.46.74.148 Jun 26 12:31:55 primo-plus ntpd[1005]: DNS: Pool skipping: 172.232.209.103 Jun 26 12:31:55 primo-plus ntpd[1005]: DNS: Pool skipping: 172.232.208.229 Jun 26 12:31:55 primo-plus ntpd[1005]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Jun 26 12:31:55 primo-plus go-librespot[5761]: go-librespot daemon starting... Jun 26 12:31:56 primo-plus go-librespot[5762]: time="2026-06-26T12:31:56+02:00" level=info msg="running go-librespot 0.7.1" Jun 26 12:31:56 primo-plus go-librespot[5762]: time="2026-06-26T12:31:56+02:00" level=debug msg="app state loaded" Jun 26 12:31:56 primo-plus go-librespot[5762]: time="2026-06-26T12:31:56+02:00" level=debug msg="stored credentials not found" Jun 26 12:31:56 primo-plus go-librespot[5762]: time="2026-06-26T12:31:56+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 26 12:31:56 primo-plus go-librespot[5762]: time="2026-06-26T12:31:56+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2026-06-26T12:31:56+02:00 is before 2026-07-09T00:00:00Z" Jun 26 12:31:56 primo-plus systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 26 12:31:56 primo-plus systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 26 12:31:56 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:31:56.323+02:00 level=INFO msg="service successfully established" component=discovery/localnet Jun 26 12:31:57 primo-plus bluealsa[903]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State Jun 26 12:31:57 primo-plus bluealsa[903]: ../src/ba-transport.c:319: New A2DP transport: 16 Jun 26 12:31:57 primo-plus bluealsa[903]: ../src/ba-transport.c:320: A2DP socket MTU: 16: R:1021 W:1024 Jun 26 12:31:57 primo-plus bluealsa[903]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State Jun 26 12:31:57 primo-plus bluealsa[903]: ../src/ba-transport.c:1075: Starting transport: A2DP Sink (SBC) Jun 26 12:31:57 primo-plus bluealsa[903]: ../src/ba-transport-pcm.c:294: Created BT socket duplicate: [16]: 17 Jun 26 12:31:57 primo-plus bluealsa[903]: ../src/ba-transport-pcm.c:373: Created new IO thread [ba-a2dp-sbc]: A2DP Sink (SBC) Jun 26 12:31:57 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: Debounce: dropped pending playback=false for 9C:73:B1:3B:D7:DA (true arrived within window) Jun 26 12:31:57 primo-plus bluealsa[903]: ../src/a2dp-sbc.c:331: PCM IO loop: START: a2dp_sbc_dec_thread: A2DP Sink (SBC) Jun 26 12:31:57 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: [dbus-next] Playback state changed: true from 9C:73:B1:3B:D7:DA Jun 26 12:31:57 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: setWinningMac: 9C:73:B1:3B:D7:DA Jun 26 12:31:57 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: Playback started, enabling output (party mode: last play wins) Jun 26 12:31:57 primo-plus volumio[1285]: info: CoreCommandRouter::volumioStop Jun 26 12:31:57 primo-plus volumio[1285]: info: CoreStateMachine::stop Jun 26 12:31:57 primo-plus volumio[1285]: info: CoreStateMachine::serviceStop Jun 26 12:31:57 primo-plus volumio[1285]: info: CoreCommandRouter::serviceStop Jun 26 12:31:57 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: [FUNC] stop Jun 26 12:31:57 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: [FUNC] btAudioOutput Jun 26 12:31:57 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: [dbus-next] Disabling Bluetooth Audio Output Jun 26 12:31:57 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: Bluetooth audio output stopped Jun 26 12:31:57 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: [FUNC] btAudioOutput Jun 26 12:31:57 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: [AAMP] Modular pipeline enabled - forcing ALSA route: volumioLocalPlayback Jun 26 12:31:57 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: Party mode: using preferred BT MAC: 9C:73:B1:3B:D7:DA Jun 26 12:31:57 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: Spawning bluealsa-aplay with args: --profile-a2dp --pcm=volumioLocalPlayback --pcm-buffer-time=500000 --pcm-period-time=100000 9C:73:B1:3B:D7:DA Jun 26 12:31:57 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: [metaCache] Loaded metadata for 9C:73:B1:3B:D7:DA from memory Jun 26 12:31:57 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: Loaded metadata from cache for 9C:73:B1:3B:D7:DA Jun 26 12:31:57 primo-plus volumio[1285]: info: CoreCommandRouter::servicePushState Jun 26 12:31:57 primo-plus volumio[1285]: info: CoreStateMachine::pushState Jun 26 12:31:57 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 26 12:31:57 primo-plus volumio[1285]: info: CoreCommandRouter::volumioPushState Jun 26 12:31:57 primo-plus volumio[1285]: info: CoreCommandRouter::volumioGetState Jun 26 12:31:57 primo-plus volumio[1285]: info: MRS: Pushing multiroomSync output update for this device Jun 26 12:31:57 primo-plus volumio[1285]: info: MRS: Pushing multiroomSync output Jun 26 12:31:57 primo-plus volumio[1285]: info: CoreCommandRouter::servicePushState Jun 26 12:31:57 primo-plus bluealsa[903]: ../src/dbus.c:47: Called: org.bluealsa.PCM1.Open() on /org/bluealsa/hci0/dev_9C_73_B1_3B_D7_DA/a2dpsnk/source Jun 26 12:31:57 primo-plus volumio[1285]: info: CoreStateMachine::pushState Jun 26 12:31:57 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 26 12:31:57 primo-plus volumio[1285]: info: CoreCommandRouter::volumioPushState Jun 26 12:31:57 primo-plus volumio[1285]: info: CoreCommandRouter::volumioGetState Jun 26 12:31:57 primo-plus volumio[1285]: info: MRS: Pushing multiroomSync output update for this device Jun 26 12:31:57 primo-plus volumio[1285]: info: MRS: Pushing multiroomSync output Jun 26 12:31:57 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:31:57.354+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" state=STATUS_PLAYING positionMs=92346 volume=40 Jun 26 12:31:57 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:31:57.355+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" state=STATUS_PLAYING positionMs=92346 volume=40 Jun 26 12:31:57 primo-plus bluealsa[903]: ../src/codec-sbc.c:278: SBC setup: 44100 Hz JointStereo allocation=Loudness blocks=16 sub-bands=8 bit-pool=53 => 327993 bps Jun 26 12:31:57 primo-plus volumio[1285]: info: Signalling Playback active due to playback status change Jun 26 12:31:57 primo-plus volumio[1285]: info: Signalling Playback active due to playback status change Jun 26 12:31:57 primo-plus volumio[1285]: info: Updating RAAT Signal Path Jun 26 12:31:57 primo-plus volumio[1285]: info: Updating RAAT Signal Path Jun 26 12:31:57 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: bluealsa-aplay stderr: bluealsa-aplay: [5770] D: aplay.c:904: Creating IO worker 9C:73:B1:3B:D7:DA Jun 26 12:31:57 primo-plus volumio[1285]: bluealsa-aplay: [5770] D: aplay.c:1320: Starting main loop Jun 26 12:31:57 primo-plus volumio[1285]: bluealsa-aplay: [5771] D: aplay.c:577: Opening BlueALSA source PCM: /org/bluealsa/hci0/dev_9C_73_B1_3B_D7_DA/a2dpsnk/source Jun 26 12:31:57 primo-plus volumio[1285]: bluealsa-aplay: [5771] D: aplay.c:603: Starting IO loop Jun 26 12:31:57 primo-plus volumio[1285]: bluealsa-aplay: [5771] D: aplay.c:732: Opening ALSA playback PCM: name=volumioLocalPlayback channels=2 rate=44100 Jun 26 12:31:57 primo-plus volumio[1285]: bluealsa-aplay: [5771] D: aplay.c:339: Opening ALSA mixer: name=default elem=Master index=0 Jun 26 12:31:57 primo-plus volumio[1285]: bluealsa-aplay: [5771] W: aplay.c:350: Couldn't open ALSA mixer: Mixer element not found Jun 26 12:31:57 primo-plus volumio[1285]: ------------------------------------ BT MESSAGE: Seek received post-resume, pushing metadata Jun 26 12:31:57 primo-plus volumio[1285]: info: CoreCommandRouter::servicePushState Jun 26 12:31:57 primo-plus volumio[1285]: info: CoreStateMachine::pushState Jun 26 12:31:57 primo-plus volumio[1285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 26 12:31:57 primo-plus volumio[1285]: info: CoreCommandRouter::volumioPushState Jun 26 12:31:57 primo-plus volumio[1285]: info: CoreCommandRouter::volumioGetState Jun 26 12:31:57 primo-plus volumio[1285]: info: MRS: Pushing multiroomSync output update for this device Jun 26 12:31:57 primo-plus volumio[1285]: info: MRS: Pushing multiroomSync output Jun 26 12:31:57 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:31:57.508+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" state=STATUS_PLAYING positionMs=92346 volume=40 Jun 26 12:31:57 primo-plus volumio[1285]: info: Signalling Playback active due to playback status change Jun 26 12:31:57 primo-plus volumio[1285]: info: Updating RAAT Signal Path Jun 26 12:31:57 primo-plus volumio[1285]: info: MCU Signalled Playback Active Jun 26 12:31:57 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:31:57.530+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" id= title="Beast Of Burden - Remastered 1994" Jun 26 12:31:57 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:31:57.588+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" id= title="Beast Of Burden - Remastered 1994" Jun 26 12:31:57 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:31:57.708+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%05 @ 0x1efba40" id= title="Beast Of Burden - Remastered 1994" Jun 26 12:31:57 primo-plus volumio[1285]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/The%20Rolling%20Stones/Some%20Girls/d9de95ad-76b9-47df-8bcd-2b829dbe9950.jpg' Jun 26 12:31:57 primo-plus volumio5-onboarding[1868]: time=2026-06-26T12:31:57.868+02:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=10.0.0.233:45304 Jun 26 12:31:57 primo-plus volumio[1285]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 26 12:31:57 primo-plus volumio[1285]: Error: certificate is not yet valid Jun 26 12:31:57 primo-plus volumio[1285]: at TLSSocket.onConnectSecure (node:_tls_wrap:1627:34) Jun 26 12:31:57 primo-plus volumio[1285]: at TLSSocket.emit (node:events:514:28) Jun 26 12:31:57 primo-plus volumio[1285]: at TLSSocket._finishInit (node:_tls_wrap:1038:8) Jun 26 12:31:57 primo-plus volumio[1285]: at ssl.onhandshakedone (node:_tls_wrap:824:12) { Jun 26 12:31:57 primo-plus volumio[1285]: code: 'CERT_NOT_YET_VALID' Jun 26 12:31:57 primo-plus volumio[1285]: } Jun 26 12:31:57 primo-plus volumio[1285]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 26 12:31:58 primo-plus sudo[5796]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-06-26 12:30' Jun 26 12:31:58 primo-plus sudo[5796]: 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="ceea798be624bcca033d94ae449c2a749a9724f0" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="9938d7179e3b7c4e41f3e2d60c255985cff08fee" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="primoplus" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed May 27 09:37:15 UTC 2026" VOLUMIO_VERSION="4.164" VOLUMIO_HARDWARE="cm4" VOLUMIO_DEVICENAME="CM4" VOLUMIO_VENDOR_MODEL="Volumio Primo Plus" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Primo Plus" VOLUMIO_HASH="c8e7083e83ff605518b1cfc23784b0e7"