Oct 29 18:36:36 volumioes9038pro systemd[1]: peppymeterbasic.service: Deactivated successfully. Oct 29 18:36:36 volumioes9038pro systemd[1]: peppymeterbasic.service: Consumed 31.952s CPU time. Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: CorePlayQueue::getTrack 1 Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: CorePlayQueue::getTrack 2 Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: Prefetching next song Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: [1761759407196] ControllerTidal::prefetch Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: Getting stream with soundQuality LOSSLESS Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: getStreamUrl took 293 milliseconds Oct 29 18:36:47 volumioes9038pro volumio[1295]: verbose: ControllerMpd::sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQzMjBkODMzZjU4NDg3YzVlMTVlYTA4OTI5NTRmYzg0OC5tcDQ/0.flac?token=1761763007~MDY1ZTM1ODU0YTliNWU1MWNmYTE5ZTJhNTViMWMxMjg3ZWNlZmZmMw==" Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: Oct 29 18:36:47 volumioes9038pro volumio[1295]: ---------------------------- MPD announces system playlist update Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: Ignoring MPD Status Update Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQzMjBkODMzZjU4NDg3YzVlMTVlYTA4OTI5NTRmYzg0OC5tcDQ/0.flac?token=1761763007~MDY1ZTM1ODU0YTliNWU1MWNmYTE5ZTJhNTViMWMxMjg3ZWNlZmZmMw==" took 1 milliseconds Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 29 18:36:47 volumioes9038pro volumio[1295]: verbose: ControllerMpd::sendMpdCommand consume 1 Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: Oct 29 18:36:47 volumioes9038pro volumio[1295]: ---------------------------- MPD announces state update: options Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: ------------------------------ 3ms Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: sendMpdCommand consume 1 took 1 milliseconds Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: ControllerMpd::getState Oct 29 18:36:47 volumioes9038pro volumio[1295]: verbose: ControllerMpd::sendMpdCommand status Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: sendMpdCommand status took 1 milliseconds Oct 29 18:36:47 volumioes9038pro volumio[1295]: verbose: ControllerMpd::parseState Oct 29 18:36:47 volumioes9038pro volumio[1295]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: sendMpdCommand playlistinfo took 0 milliseconds Oct 29 18:36:47 volumioes9038pro volumio[1295]: verbose: ControllerMpd::parseTrackInfo Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: ControllerMpd::pushState Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: CoreCommandRouter::servicePushState Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: CorePlayQueue::getTrack 1 Oct 29 18:36:47 volumioes9038pro volumio[1295]: verbose: STATE SERVICE {"status":"play","position":0,"seek":191700,"duration":195,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1 Kbps","isStreaming":false,"title":"0.flac?token=1761762742~NGY0Y2E0YWEwZDBjMDQ4NGFiN2YyNDIyY2U2MmMwZjJjM2FhODRjYw==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQzMWQzNzViYTZkZDcyMzI5YmQyYWNjMWFkMGNjOTA4ZC5tcDQ/0.flac?token=1761762742~NGY0Y2E0YWEwZDBjMDQ4NGFiN2YyNDIyY2U2MmMwZjJjM2FhODRjYw==","trackType":"tidal"} Oct 29 18:36:47 volumioes9038pro volumio[1295]: verbose: CURRENT POSITION 1 Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: CoreStateMachine::syncState stateService play Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: CoreStateMachine::syncState currentStatus play Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: Received an update from plugin. extracting info from payload Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: CoreStateMachine::pushState Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: CoreCommandRouter::volumioPushState Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: MRS: Pushing multiroomSync output update for this device Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: MRS: Pushing multiroomSync output Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: CoreCommandRouter::volumioGetState Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: CoreStateMachine::pushState Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: CoreCommandRouter::volumioPushState Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: MRS: Pushing multiroomSync output update for this device Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: MRS: Pushing multiroomSync output Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: CoreCommandRouter::volumioGetState Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: ------------------------------ 24ms Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 29 18:36:47 volumioes9038pro sudo[3714]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 29 18:36:47 volumioes9038pro sudo[3714]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 29 18:36:47 volumioes9038pro sudo[3717]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 29 18:36:47 volumioes9038pro sudo[3717]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 29 18:36:47 volumioes9038pro systemd[1]: Started peppymeterbasic.service - peppymeterbasic Daemon. Oct 29 18:36:47 volumioes9038pro sudo[3714]: pam_unix(sudo:session): session closed for user root Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: peppymeterbasic Daemon Started Oct 29 18:36:47 volumioes9038pro sudo[3717]: pam_unix(sudo:session): session closed for user root Oct 29 18:36:47 volumioes9038pro volumio[1295]: info: peppymeterbasic Daemon Started Oct 29 18:36:48 volumioes9038pro volumio[3723]: Failed to create /home/volumio/.cache/mesa_shader_cache for shader cache (Permission denied)---disabling. Oct 29 18:36:48 volumioes9038pro volumio[3723]: Failed to create /home/volumio/.cache/mesa_shader_cache_db for shader cache (Permission denied)---disabling. Oct 29 18:36:48 volumioes9038pro volumio[3723]: libpng warning: iCCP: known incorrect sRGB profile Oct 29 18:36:48 volumioes9038pro volumio[3723]: libpng warning: iCCP: known incorrect sRGB profile Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: Oct 29 18:36:50 volumioes9038pro volumio[1295]: ---------------------------- MPD announces system playlist update Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: Ignoring MPD Status Update Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: Oct 29 18:36:50 volumioes9038pro volumio[1295]: ---------------------------- MPD announces state update: player Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: ControllerMpd::getState Oct 29 18:36:50 volumioes9038pro volumio[1295]: verbose: ControllerMpd::sendMpdCommand status Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: ------------------------------ 2ms Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: sendMpdCommand status took 1 milliseconds Oct 29 18:36:50 volumioes9038pro volumio[1295]: verbose: ControllerMpd::parseState Oct 29 18:36:50 volumioes9038pro volumio[1295]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 29 18:36:50 volumioes9038pro volumio[1295]: verbose: ControllerMpd::parseTrackInfo Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: ControllerMpd::pushState Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: CoreCommandRouter::servicePushState Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: CorePlayQueue::getTrack 1 Oct 29 18:36:50 volumioes9038pro volumio[1295]: verbose: STATE SERVICE {"status":"play","position":0,"seek":91,"duration":163,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"526 Kbps","isStreaming":false,"title":"0.flac?token=1761763007~MDY1ZTM1ODU0YTliNWU1MWNmYTE5ZTJhNTViMWMxMjg3ZWNlZmZmMw==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQzMjBkODMzZjU4NDg3YzVlMTVlYTA4OTI5NTRmYzg0OC5tcDQ/0.flac?token=1761763007~MDY1ZTM1ODU0YTliNWU1MWNmYTE5ZTJhNTViMWMxMjg3ZWNlZmZmMw==","trackType":"tidal"} Oct 29 18:36:50 volumioes9038pro volumio[1295]: verbose: CURRENT POSITION 1 Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: CoreStateMachine::syncState stateService play Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: CoreStateMachine::syncState currentStatus play Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: Received an update from plugin. extracting info from payload Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: CoreStateMachine::pushState Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: CoreCommandRouter::volumioPushState Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: MRS: Pushing multiroomSync output update for this device Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: MRS: Pushing multiroomSync output Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: CoreCommandRouter::volumioGetState Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: CoreStateMachine::pushState Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: CoreCommandRouter::volumioPushState Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: MRS: Pushing multiroomSync output update for this device Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: MRS: Pushing multiroomSync output Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: CoreCommandRouter::volumioGetState Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: ------------------------------ 18ms Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 29 18:36:50 volumioes9038pro sudo[3730]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 29 18:36:50 volumioes9038pro sudo[3730]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 29 18:36:50 volumioes9038pro sudo[3732]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 29 18:36:50 volumioes9038pro sudo[3732]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 29 18:36:50 volumioes9038pro sudo[3730]: pam_unix(sudo:session): session closed for user root Oct 29 18:36:50 volumioes9038pro sudo[3732]: pam_unix(sudo:session): session closed for user root Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: peppymeterbasic Daemon Started Oct 29 18:36:50 volumioes9038pro volumio[1295]: info: peppymeterbasic Daemon Started Oct 29 18:36:51 volumioes9038pro volumio[1295]: info: CoreStateMachine::startPlaybackTimer Oct 29 18:36:51 volumioes9038pro volumio[1295]: info: CorePlayQueue::getTrack 2 Oct 29 18:36:52 volumioes9038pro volumio[1295]: info: CoreStateMachine::pushState Oct 29 18:36:52 volumioes9038pro volumio[1295]: info: CorePlayQueue::getTrack 2 Oct 29 18:36:52 volumioes9038pro volumio[1295]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 18:36:52 volumioes9038pro volumio[1295]: info: CoreCommandRouter::volumioPushState Oct 29 18:36:52 volumioes9038pro volumio[1295]: info: MRS: Pushing multiroomSync output update for this device Oct 29 18:36:52 volumioes9038pro volumio[1295]: info: MRS: Pushing multiroomSync output Oct 29 18:36:52 volumioes9038pro volumio[1295]: info: CoreCommandRouter::volumioGetState Oct 29 18:36:52 volumioes9038pro volumio[1295]: info: CorePlayQueue::getTrack 2 Oct 29 18:36:52 volumioes9038pro volumio[1295]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 29 18:36:52 volumioes9038pro sudo[3736]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 29 18:36:52 volumioes9038pro sudo[3736]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 29 18:36:52 volumioes9038pro sudo[3736]: pam_unix(sudo:session): session closed for user root Oct 29 18:36:52 volumioes9038pro volumio[1295]: info: peppymeterbasic Daemon Started Oct 29 18:37:00 volumioes9038pro nmbd[1158]: [2025/10/29 18:37:00.570632, 0] ../../source3/nmbd/nmbd_nameregister.c:73(register_name_response) Oct 29 18:37:00 volumioes9038pro nmbd[1158]: register_name_response: Answer name <00> differs from question name <00>. Oct 29 18:37:00 volumioes9038pro nmbd[1158]: [2025/10/29 18:37:00.570840, 0] ../../source3/nmbd/nmbd_nameregister.c:73(register_name_response) Oct 29 18:37:00 volumioes9038pro nmbd[1158]: register_name_response: Answer name <03> differs from question name <03>. Oct 29 18:37:00 volumioes9038pro nmbd[1158]: [2025/10/29 18:37:00.570949, 0] ../../source3/nmbd/nmbd_nameregister.c:73(register_name_response) Oct 29 18:37:00 volumioes9038pro nmbd[1158]: register_name_response: Answer name <20> differs from question name <20>. Oct 29 18:37:15 volumioes9038pro go-librespot[1969]: time="2025-10-29T18:37:15+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Oct 29 18:37:15 volumioes9038pro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 29 18:37:15 volumioes9038pro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 29 18:37:15 volumioes9038pro volumio[1295]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 29 18:37:15 volumioes9038pro volumio[1295]: Error: socket hang up Oct 29 18:37:15 volumioes9038pro volumio[1295]: at connResetException (node:internal/errors:720:14) Oct 29 18:37:15 volumioes9038pro volumio[1295]: at Socket.socketOnEnd (node:_http_client:519:23) Oct 29 18:37:15 volumioes9038pro volumio[1295]: at Socket.emit (node:events:526:35) Oct 29 18:37:15 volumioes9038pro volumio[1295]: at endReadableNT (node:internal/streams/readable:1376:12) Oct 29 18:37:15 volumioes9038pro volumio[1295]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Oct 29 18:37:15 volumioes9038pro volumio[1295]: code: 'ECONNRESET', Oct 29 18:37:15 volumioes9038pro volumio[1295]: response: undefined Oct 29 18:37:15 volumioes9038pro volumio[1295]: } Oct 29 18:37:15 volumioes9038pro volumio[1295]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 29 18:37:15 volumioes9038pro sudo[3802]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-10-29 18:36' Oct 29 18:37:15 volumioes9038pro sudo[3802]: 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="5ef3d56f987d109f3e21bfa246dbbb723cf6a917" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="c7bff9654d2984a81c5720476c2c8ac531869c54" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Oct 9 18:08:11 UTC 2025" VOLUMIO_VERSION="4.062" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="00524295c246b7d72f125e4c54b86a88"