Mar 26 18:27:03 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: Received new metadata for AC:49:DB:3F:D5:09 Mar 26 18:27:03 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: [metaCache] Saved metadata to /tmp/bluetooth-cache/meta-AC:49:DB:3F:D5:09.json Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::servicePushState Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreStateMachine::pushState Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioPushState Mar 26 18:27:03 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output update for this device Mar 26 18:27:03 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioGetState Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::servicePushState Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreStateMachine::pushState Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioPushState Mar 26 18:27:03 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output update for this device Mar 26 18:27:03 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioGetState Mar 26 18:27:03 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: [dbus-next] Playback state changed: false from AC:49:DB:3F:D5:09 Mar 26 18:27:03 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: Received pause signal from winner, scheduling idle check Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::servicePushState Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreStateMachine::pushState Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioPushState Mar 26 18:27:03 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output update for this device Mar 26 18:27:03 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioGetState Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::servicePushState Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreStateMachine::pushState Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioPushState Mar 26 18:27:03 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output update for this device Mar 26 18:27:03 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioGetState Mar 26 18:27:03 volumio-touch volumio[1431]: info: touch_display: Setting screensaver timeout to 120 seconds. Mar 26 18:27:03 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: Received new metadata for AC:49:DB:3F:D5:09 Mar 26 18:27:03 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: [metaCache] Saved metadata to /tmp/bluetooth-cache/meta-AC:49:DB:3F:D5:09.json Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::servicePushState Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreStateMachine::pushState Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioPushState Mar 26 18:27:03 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output update for this device Mar 26 18:27:03 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioGetState Mar 26 18:27:03 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: Received new metadata for AC:49:DB:3F:D5:09 Mar 26 18:27:03 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: [metaCache] Saved metadata to /tmp/bluetooth-cache/meta-AC:49:DB:3F:D5:09.json Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::servicePushState Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreStateMachine::pushState Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioPushState Mar 26 18:27:03 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output update for this device Mar 26 18:27:03 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioGetState Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::servicePushState Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreStateMachine::pushState Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioPushState Mar 26 18:27:03 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output update for this device Mar 26 18:27:03 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioGetState Mar 26 18:27:03 volumio-touch volumio[1431]: info: touch_display: Setting screensaver timeout to 0 seconds. Mar 26 18:27:03 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: Received new metadata for AC:49:DB:3F:D5:09 Mar 26 18:27:03 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: [metaCache] Saved metadata to /tmp/bluetooth-cache/meta-AC:49:DB:3F:D5:09.json Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::servicePushState Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreStateMachine::pushState Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioPushState Mar 26 18:27:03 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output update for this device Mar 26 18:27:03 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioGetState Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::servicePushState Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreStateMachine::pushState Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioPushState Mar 26 18:27:03 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output update for this device Mar 26 18:27:03 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output Mar 26 18:27:03 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioGetState Mar 26 18:27:05 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: Playback resumed before idle timeout Mar 26 18:27:05 volumio-touch bluealsa[1134]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State Mar 26 18:27:05 volumio-touch bluealsa[1134]: ../src/ba-transport-pcm.c:307: Closing BT socket duplicate [15]: 18 Mar 26 18:27:05 volumio-touch bluealsa[1134]: ../src/ba-transport.c:381: Closing A2DP transport: 15 Mar 26 18:27:05 volumio-touch bluealsa[1134]: ../src/ba-transport-pcm.c:257: Exiting IO thread [ba-a2dp-sbc]: A2DP Sink (SBC) Mar 26 18:27:05 volumio-touch volumio[1431]: An internal error occurred while serving an albumart. Details: NotFoundError: Not Found Mar 26 18:27:05 volumio-touch volumio[1431]: at createHttpError (/volumio/node_modules/send/index.js:979:12) Mar 26 18:27:05 volumio-touch volumio[1431]: at SendStream.error (/volumio/node_modules/send/index.js:270:31) Mar 26 18:27:05 volumio-touch volumio[1431]: at SendStream.pipe (/volumio/node_modules/send/index.js:580:14) Mar 26 18:27:05 volumio-touch volumio[1431]: at sendfile (/volumio/node_modules/express/lib/response.js:1139:8) Mar 26 18:27:05 volumio-touch volumio[1431]: at ServerResponse.sendFile (/volumio/node_modules/express/lib/response.js:450:3) Mar 26 18:27:05 volumio-touch volumio[1431]: at Promise._failFn (/volumio/app/plugins/miscellanea/albumart/albumart.js:449:13) Mar 26 18:27:05 volumio-touch volumio[1431]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Mar 26 18:27:05 volumio-touch volumio[1431]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Mar 26 18:27:05 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: bluealsa-aplay stderr: bluealsa-aplay: [2691] D: aplay.c:643: BT device marked as inactive: AC:49:DB:3F:D5:09 Mar 26 18:27:05 volumio-touch volumio[1431]: An internal error occurred while serving an albumart. Details: NotFoundError: Not Found Mar 26 18:27:05 volumio-touch volumio[1431]: at createHttpError (/volumio/node_modules/send/index.js:979:12) Mar 26 18:27:05 volumio-touch volumio[1431]: at SendStream.error (/volumio/node_modules/send/index.js:270:31) Mar 26 18:27:05 volumio-touch volumio[1431]: at SendStream.pipe (/volumio/node_modules/send/index.js:580:14) Mar 26 18:27:05 volumio-touch volumio[1431]: at sendfile (/volumio/node_modules/express/lib/response.js:1139:8) Mar 26 18:27:05 volumio-touch volumio[1431]: at ServerResponse.sendFile (/volumio/node_modules/express/lib/response.js:450:3) Mar 26 18:27:05 volumio-touch volumio[1431]: at Promise._failFn (/volumio/app/plugins/miscellanea/albumart/albumart.js:449:13) Mar 26 18:27:05 volumio-touch volumio[1431]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Mar 26 18:27:05 volumio-touch volumio[1431]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Mar 26 18:27:05 volumio-touch volumio[1431]: info: Executing endpoint metavolumio Mar 26 18:27:05 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 26 18:27:05 volumio-touch volumio[1431]: info: Executing endpoint metavolumio Mar 26 18:27:05 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 26 18:27:05 volumio-touch volumio[1431]: info: Executing endpoint metavolumio Mar 26 18:27:05 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 26 18:27:06 volumio-touch volumio[1431]: An internal error occurred while serving an albumart. Details: NotFoundError: Not Found Mar 26 18:27:06 volumio-touch volumio[1431]: at createHttpError (/volumio/node_modules/send/index.js:979:12) Mar 26 18:27:06 volumio-touch volumio[1431]: at SendStream.error (/volumio/node_modules/send/index.js:270:31) Mar 26 18:27:06 volumio-touch volumio[1431]: at SendStream.pipe (/volumio/node_modules/send/index.js:580:14) Mar 26 18:27:06 volumio-touch volumio[1431]: at sendfile (/volumio/node_modules/express/lib/response.js:1139:8) Mar 26 18:27:06 volumio-touch volumio[1431]: at ServerResponse.sendFile (/volumio/node_modules/express/lib/response.js:450:3) Mar 26 18:27:06 volumio-touch volumio[1431]: at Promise._failFn (/volumio/app/plugins/miscellanea/albumart/albumart.js:449:13) Mar 26 18:27:06 volumio-touch volumio[1431]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Mar 26 18:27:06 volumio-touch volumio[1431]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Mar 26 18:27:07 volumio-touch bluealsa[1134]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State Mar 26 18:27:07 volumio-touch bluealsa[1134]: ../src/ba-transport.c:319: New A2DP transport: 15 Mar 26 18:27:07 volumio-touch bluealsa[1134]: ../src/ba-transport.c:320: A2DP socket MTU: 15: R:1021 W:1004 Mar 26 18:27:07 volumio-touch bluealsa[1134]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State Mar 26 18:27:07 volumio-touch bluealsa[1134]: ../src/ba-transport.c:1075: Starting transport: A2DP Sink (SBC) Mar 26 18:27:07 volumio-touch bluealsa[1134]: ../src/ba-transport-pcm.c:294: Created BT socket duplicate: [15]: 18 Mar 26 18:27:07 volumio-touch bluealsa[1134]: ../src/a2dp-sbc.c:331: PCM IO loop: START: a2dp_sbc_dec_thread: A2DP Sink (SBC) Mar 26 18:27:07 volumio-touch bluealsa[1134]: ../src/ba-transport-pcm.c:373: Created new IO thread [ba-a2dp-sbc]: A2DP Sink (SBC) Mar 26 18:27:07 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: [dbus-next] Playback state changed: true from AC:49:DB:3F:D5:09 Mar 26 18:27:07 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: setWinningMac: AC:49:DB:3F:D5:09 Mar 26 18:27:07 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: Playback started, enabling output (party mode: last play wins) Mar 26 18:27:07 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: [FUNC] btAudioOutput Mar 26 18:27:07 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: [AAMP] Modular pipeline enabled - forcing ALSA route: volumioLocalPlayback Mar 26 18:27:07 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: Party mode: using preferred BT MAC: AC:49:DB:3F:D5:09 Mar 26 18:27:07 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: bluealsa-aplay already running for AC:49:DB:3F:D5:09. Skipping. Mar 26 18:27:07 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: [metaCache] Loaded metadata for AC:49:DB:3F:D5:09 from memory Mar 26 18:27:07 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: Loaded metadata from cache for AC:49:DB:3F:D5:09 Mar 26 18:27:07 volumio-touch volumio[1431]: info: CoreCommandRouter::servicePushState Mar 26 18:27:07 volumio-touch volumio[1431]: info: CoreStateMachine::pushState Mar 26 18:27:07 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 18:27:07 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioPushState Mar 26 18:27:07 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output update for this device Mar 26 18:27:07 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output Mar 26 18:27:07 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioGetState Mar 26 18:27:07 volumio-touch volumio[1431]: info: CoreCommandRouter::servicePushState Mar 26 18:27:07 volumio-touch volumio[1431]: info: CoreStateMachine::pushState Mar 26 18:27:07 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 18:27:07 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioPushState Mar 26 18:27:07 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output update for this device Mar 26 18:27:07 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output Mar 26 18:27:07 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioGetState Mar 26 18:27:07 volumio-touch bluealsa[1134]: ../src/codec-sbc.c:278: SBC setup: 44100 Hz JointStereo allocation=Loudness blocks=16 sub-bands=8 bit-pool=53 => 327993 bps Mar 26 18:27:07 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: bluealsa-aplay stderr: bluealsa-aplay: [2691] D: aplay.c:732: Opening ALSA playback PCM: name=volumioLocalPlayback channels=2 rate=44100 Mar 26 18:27:07 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: bluealsa-aplay stderr: bluealsa-aplay: [2691] D: aplay.c:339: Opening ALSA mixer: name=default elem=Master index=0 Mar 26 18:27:07 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: bluealsa-aplay stderr: bluealsa-aplay: [2691] W: aplay.c:350: Couldn't open ALSA mixer: Mixer element not found Mar 26 18:27:08 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: Seek received post-resume, pushing metadata Mar 26 18:27:08 volumio-touch volumio[1431]: info: CoreCommandRouter::servicePushState Mar 26 18:27:08 volumio-touch volumio[1431]: info: CoreStateMachine::pushState Mar 26 18:27:08 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 18:27:08 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioPushState Mar 26 18:27:08 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output update for this device Mar 26 18:27:08 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output Mar 26 18:27:08 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioGetState Mar 26 18:27:15 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: Received new metadata for AC:49:DB:3F:D5:09 Mar 26 18:27:15 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: [metaCache] Saved metadata to /tmp/bluetooth-cache/meta-AC:49:DB:3F:D5:09.json Mar 26 18:27:15 volumio-touch volumio[1431]: info: CoreCommandRouter::servicePushState Mar 26 18:27:15 volumio-touch volumio[1431]: info: CoreStateMachine::pushState Mar 26 18:27:15 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 18:27:15 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioPushState Mar 26 18:27:15 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output update for this device Mar 26 18:27:15 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output Mar 26 18:27:15 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioGetState Mar 26 18:27:15 volumio-touch volumio[1431]: info: CoreCommandRouter::servicePushState Mar 26 18:27:15 volumio-touch volumio[1431]: info: CoreStateMachine::pushState Mar 26 18:27:15 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 18:27:15 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioPushState Mar 26 18:27:15 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output update for this device Mar 26 18:27:15 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output Mar 26 18:27:15 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioGetState Mar 26 18:27:16 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: [dbus-next] Playback state changed: false from AC:49:DB:3F:D5:09 Mar 26 18:27:16 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: Received pause signal from winner, scheduling idle check Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreCommandRouter::servicePushState Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreStateMachine::pushState Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioPushState Mar 26 18:27:16 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output update for this device Mar 26 18:27:16 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioGetState Mar 26 18:27:16 volumio-touch volumio[1431]: info: touch_display: Setting screensaver timeout to 120 seconds. Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreCommandRouter::servicePushState Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreStateMachine::pushState Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioPushState Mar 26 18:27:16 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output update for this device Mar 26 18:27:16 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioGetState Mar 26 18:27:16 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: Received new metadata for AC:49:DB:3F:D5:09 Mar 26 18:27:16 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: [metaCache] Saved metadata to /tmp/bluetooth-cache/meta-AC:49:DB:3F:D5:09.json Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreCommandRouter::servicePushState Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreStateMachine::pushState Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioPushState Mar 26 18:27:16 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output update for this device Mar 26 18:27:16 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioGetState Mar 26 18:27:16 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: Received new metadata for AC:49:DB:3F:D5:09 Mar 26 18:27:16 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: [metaCache] Saved metadata to /tmp/bluetooth-cache/meta-AC:49:DB:3F:D5:09.json Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreCommandRouter::servicePushState Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreStateMachine::pushState Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioPushState Mar 26 18:27:16 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output update for this device Mar 26 18:27:16 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioGetState Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreCommandRouter::servicePushState Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreStateMachine::pushState Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioPushState Mar 26 18:27:16 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output update for this device Mar 26 18:27:16 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioGetState Mar 26 18:27:16 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: Received new metadata for AC:49:DB:3F:D5:09 Mar 26 18:27:16 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: [metaCache] Saved metadata to /tmp/bluetooth-cache/meta-AC:49:DB:3F:D5:09.json Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreCommandRouter::servicePushState Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreStateMachine::pushState Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioPushState Mar 26 18:27:16 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output update for this device Mar 26 18:27:16 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioGetState Mar 26 18:27:16 volumio-touch volumio[1431]: info: touch_display: Setting screensaver timeout to 0 seconds. Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreCommandRouter::servicePushState Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreStateMachine::pushState Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioPushState Mar 26 18:27:16 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output update for this device Mar 26 18:27:16 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output Mar 26 18:27:16 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioGetState Mar 26 18:27:17 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: Playback resumed before idle timeout Mar 26 18:27:17 volumio-touch bluealsa[1134]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State Mar 26 18:27:17 volumio-touch bluealsa[1134]: ../src/ba-transport-pcm.c:307: Closing BT socket duplicate [15]: 18 Mar 26 18:27:17 volumio-touch bluealsa[1134]: ../src/ba-transport.c:381: Closing A2DP transport: 15 Mar 26 18:27:17 volumio-touch bluealsa[1134]: ../src/ba-transport-pcm.c:257: Exiting IO thread [ba-a2dp-sbc]: A2DP Sink (SBC) Mar 26 18:27:17 volumio-touch volumio[1431]: An internal error occurred while serving an albumart. Details: NotFoundError: Not Found Mar 26 18:27:17 volumio-touch volumio[1431]: at createHttpError (/volumio/node_modules/send/index.js:979:12) Mar 26 18:27:17 volumio-touch volumio[1431]: at SendStream.error (/volumio/node_modules/send/index.js:270:31) Mar 26 18:27:17 volumio-touch volumio[1431]: at SendStream.pipe (/volumio/node_modules/send/index.js:580:14) Mar 26 18:27:17 volumio-touch volumio[1431]: at sendfile (/volumio/node_modules/express/lib/response.js:1139:8) Mar 26 18:27:17 volumio-touch volumio[1431]: at ServerResponse.sendFile (/volumio/node_modules/express/lib/response.js:450:3) Mar 26 18:27:17 volumio-touch volumio[1431]: at Promise._failFn (/volumio/app/plugins/miscellanea/albumart/albumart.js:449:13) Mar 26 18:27:17 volumio-touch volumio[1431]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Mar 26 18:27:17 volumio-touch volumio[1431]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Mar 26 18:27:18 volumio-touch volumio[1431]: An internal error occurred while serving an albumart. Details: NotFoundError: Not Found Mar 26 18:27:18 volumio-touch volumio[1431]: at createHttpError (/volumio/node_modules/send/index.js:979:12) Mar 26 18:27:18 volumio-touch volumio[1431]: at SendStream.error (/volumio/node_modules/send/index.js:270:31) Mar 26 18:27:18 volumio-touch volumio[1431]: at SendStream.pipe (/volumio/node_modules/send/index.js:580:14) Mar 26 18:27:18 volumio-touch volumio[1431]: at sendfile (/volumio/node_modules/express/lib/response.js:1139:8) Mar 26 18:27:18 volumio-touch volumio[1431]: at ServerResponse.sendFile (/volumio/node_modules/express/lib/response.js:450:3) Mar 26 18:27:18 volumio-touch volumio[1431]: at Promise._failFn (/volumio/app/plugins/miscellanea/albumart/albumart.js:449:13) Mar 26 18:27:18 volumio-touch volumio[1431]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Mar 26 18:27:18 volumio-touch volumio[1431]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Mar 26 18:27:18 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: bluealsa-aplay stderr: bluealsa-aplay: [2691] D: aplay.c:643: BT device marked as inactive: AC:49:DB:3F:D5:09 Mar 26 18:27:18 volumio-touch volumio[1431]: info: Executing endpoint metavolumio Mar 26 18:27:18 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 26 18:27:18 volumio-touch volumio[1431]: info: Executing endpoint metavolumio Mar 26 18:27:18 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 26 18:27:18 volumio-touch volumio[1431]: info: Executing endpoint metavolumio Mar 26 18:27:18 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 26 18:27:18 volumio-touch volumio[1431]: An internal error occurred while serving an albumart. Details: NotFoundError: Not Found Mar 26 18:27:18 volumio-touch volumio[1431]: at createHttpError (/volumio/node_modules/send/index.js:979:12) Mar 26 18:27:18 volumio-touch volumio[1431]: at SendStream.error (/volumio/node_modules/send/index.js:270:31) Mar 26 18:27:18 volumio-touch volumio[1431]: at SendStream.pipe (/volumio/node_modules/send/index.js:580:14) Mar 26 18:27:18 volumio-touch volumio[1431]: at sendfile (/volumio/node_modules/express/lib/response.js:1139:8) Mar 26 18:27:18 volumio-touch volumio[1431]: at ServerResponse.sendFile (/volumio/node_modules/express/lib/response.js:450:3) Mar 26 18:27:18 volumio-touch volumio[1431]: at Promise._failFn (/volumio/app/plugins/miscellanea/albumart/albumart.js:449:13) Mar 26 18:27:18 volumio-touch volumio[1431]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Mar 26 18:27:18 volumio-touch volumio[1431]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Mar 26 18:27:22 volumio-touch bluealsa[1134]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State Mar 26 18:27:22 volumio-touch bluealsa[1134]: ../src/ba-transport.c:319: New A2DP transport: 15 Mar 26 18:27:22 volumio-touch bluealsa[1134]: ../src/ba-transport.c:320: A2DP socket MTU: 15: R:1021 W:1004 Mar 26 18:27:22 volumio-touch bluealsa[1134]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State Mar 26 18:27:22 volumio-touch bluealsa[1134]: ../src/ba-transport.c:1075: Starting transport: A2DP Sink (SBC) Mar 26 18:27:22 volumio-touch bluealsa[1134]: ../src/ba-transport-pcm.c:294: Created BT socket duplicate: [15]: 18 Mar 26 18:27:22 volumio-touch bluealsa[1134]: ../src/a2dp-sbc.c:331: PCM IO loop: START: a2dp_sbc_dec_thread: A2DP Sink (SBC) Mar 26 18:27:22 volumio-touch bluealsa[1134]: ../src/ba-transport-pcm.c:373: Created new IO thread [ba-a2dp-sbc]: A2DP Sink (SBC) Mar 26 18:27:22 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: [dbus-next] Playback state changed: true from AC:49:DB:3F:D5:09 Mar 26 18:27:22 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: setWinningMac: AC:49:DB:3F:D5:09 Mar 26 18:27:22 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: Playback started, enabling output (party mode: last play wins) Mar 26 18:27:22 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: [FUNC] btAudioOutput Mar 26 18:27:22 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: [AAMP] Modular pipeline enabled - forcing ALSA route: volumioLocalPlayback Mar 26 18:27:22 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: Party mode: using preferred BT MAC: AC:49:DB:3F:D5:09 Mar 26 18:27:22 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: bluealsa-aplay already running for AC:49:DB:3F:D5:09. Skipping. Mar 26 18:27:22 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: [metaCache] Loaded metadata for AC:49:DB:3F:D5:09 from memory Mar 26 18:27:22 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: Loaded metadata from cache for AC:49:DB:3F:D5:09 Mar 26 18:27:22 volumio-touch volumio[1431]: info: CoreCommandRouter::servicePushState Mar 26 18:27:22 volumio-touch volumio[1431]: info: CoreStateMachine::pushState Mar 26 18:27:22 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 18:27:22 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioPushState Mar 26 18:27:22 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output update for this device Mar 26 18:27:22 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output Mar 26 18:27:22 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioGetState Mar 26 18:27:22 volumio-touch volumio[1431]: info: CoreCommandRouter::servicePushState Mar 26 18:27:22 volumio-touch volumio[1431]: info: CoreStateMachine::pushState Mar 26 18:27:22 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 18:27:22 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioPushState Mar 26 18:27:22 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output update for this device Mar 26 18:27:22 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output Mar 26 18:27:22 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioGetState Mar 26 18:27:22 volumio-touch bluealsa[1134]: ../src/codec-sbc.c:278: SBC setup: 44100 Hz JointStereo allocation=Loudness blocks=16 sub-bands=8 bit-pool=53 => 327993 bps Mar 26 18:27:22 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: bluealsa-aplay stderr: bluealsa-aplay: [2691] D: aplay.c:732: Opening ALSA playback PCM: name=volumioLocalPlayback channels=2 rate=44100 Mar 26 18:27:22 volumio-touch volumio[1431]: bluealsa-aplay: [2691] D: aplay.c:339: Opening ALSA mixer: name=default elem=Master index=0 Mar 26 18:27:22 volumio-touch volumio[1431]: bluealsa-aplay: [2691] W: aplay.c:350: Couldn't open ALSA mixer: Mixer element not found Mar 26 18:27:22 volumio-touch volumio[1431]: ------------------------------------ BT MESSAGE: Seek received post-resume, pushing metadata Mar 26 18:27:22 volumio-touch volumio[1431]: info: CoreCommandRouter::servicePushState Mar 26 18:27:22 volumio-touch volumio[1431]: info: CoreStateMachine::pushState Mar 26 18:27:22 volumio-touch volumio[1431]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 18:27:22 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioPushState Mar 26 18:27:22 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output update for this device Mar 26 18:27:22 volumio-touch volumio[1431]: info: MRS: Pushing multiroomSync output Mar 26 18:27:22 volumio-touch volumio[1431]: info: CoreCommandRouter::volumioGetState Mar 26 18:28:06 volumio-touch volumio[1431]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 26 18:28:06 volumio-touch volumio[1431]: Error: read ECONNRESET Mar 26 18:28:06 volumio-touch volumio[1431]: at TLSWrap.onStreamRead (node:internal/stream_base_commons:217:20) { Mar 26 18:28:06 volumio-touch volumio[1431]: errno: -104, Mar 26 18:28:06 volumio-touch volumio[1431]: code: 'ECONNRESET', Mar 26 18:28:06 volumio-touch volumio[1431]: syscall: 'read' Mar 26 18:28:06 volumio-touch volumio[1431]: } Mar 26 18:28:06 volumio-touch volumio[1431]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 26 18:28:06 volumio-touch sudo[4095]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-26 18:27' Mar 26 18:28:06 volumio-touch sudo[4095]: 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="dc61260dec5515dafd2b634881860b4c46c919ff" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Mar 6 16:46:58 UTC 2026" VOLUMIO_VERSION="4.103" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="aa741395b8bfc648ff5d04e312f53d2c"