May 25 15:10:12 motivo volumio-remote-updater[2940]: [2026-05-25 13:10:12] [connect] Successful connection May 25 15:10:25 motivo bluealsa[1126]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_4A_71_E4_F7_6C_32, ...) May 25 15:10:53 motivo systemd-udevd[551]: hci0:65: Worker [8829] processing SEQNUM=3076 is taking a long time May 25 15:11:07 motivo volumio-remote-updater[2940]: [2026-05-25 13:11:07] [connect] Successful connection May 25 15:11:08 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service0001/char0002, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service0001/char0004, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service0001, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service0006/char0007/desc0009, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service0006/char0007, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service0006, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service000a/char000b, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service000a/char000d, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service000a, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service000f/char0010/desc0012, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service000f/char0010/desc0013, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service000f/char0010, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service000f, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service0014/char0015/desc0017, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service0014/char0015/desc0018, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service0014/char0015, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service0014, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service0019/char001a/desc001c, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service0019/char001a, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service0019, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service001d/char001e/desc0020, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service001d/char001e, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service001d/char0021, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service001d, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service0023/char0024/desc0026, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service0023/char0024, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service0023/char0027/desc0029, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service0023/char0027, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service0023/char002a/desc002c, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service0023/char002a, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service0023, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service002d/char002e/desc0030, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service002d/char002e/desc0031, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service002d/char002e, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service002d/char0032/desc0034, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service002d/char0032/desc0035, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service002d/char0032, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service002d/char0036/desc0038, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service002d/char0036, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83/service002d, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_5E_29_81_C9_EB_83, ...) May 25 15:11:17 motivo bluealsa[1126]: bluez.c:1393: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved(/org/bluez/hci0/dev_4A_71_E4_F7_6C_32, ...) May 25 15:11:21 motivo systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... May 25 15:11:22 motivo volumio5-onboarding[1834]: time=2026-05-25T13:11:22.611Z level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.32.3:56174 May 25 15:11:24 motivo volumio5-onboarding[1834]: time=2026-05-25T13:11:23.818Z level=INFO msg="connection to address closed" component=conn/multi addr=192.168.32.3:56174 May 25 15:11:25 motivo volumio5-onboarding[1834]: time=2026-05-25T13:11:24.501Z level=ERROR msg="failed to upgrade connection" component=conn/ws remoteAddr=192.168.32.3:57208 error="write tcp 192.168.32.9:7331->192.168.32.3:57208: write: broken pipe" May 25 15:11:25 motivo volumio5-onboarding[1834]: time=2026-05-25T13:11:24.500Z level=ERROR msg="failed to upgrade connection" component=conn/ws remoteAddr=192.168.32.3:57209 error="write tcp 192.168.32.9:7331->192.168.32.3:57209: write: broken pipe" May 25 15:11:25 motivo volumio5-onboarding[1834]: time=2026-05-25T13:11:24.510Z level=ERROR msg="failed to upgrade connection" component=conn/ws remoteAddr=192.168.32.3:57207 error="write tcp 192.168.32.9:7331->192.168.32.3:57207: write: broken pipe" May 25 15:11:24 motivo dbus-daemon[806]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.19" (uid=0 pid=1834 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.6" (uid=0 pid=1066 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") May 25 15:11:25 motivo volumio5-onboarding[1834]: time=2026-05-25T13:11:25.373Z level=ERROR msg="failed to cancel pairing for disconnected device" component=ble/conn device=4A:71:E4:F7:6C:32 error="Method \"CancelPairing\" with signature \"\" on interface \"org.bluez.Device1\" doesn't exist\n" May 25 15:11:25 motivo volumio-remote-updater[2940]: [2026-05-25 13:11:25] [connect] Successful connection May 25 15:11:27 motivo volumio[1266]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 25 15:11:28 motivo volumio[1266]: Error: write EPIPE May 25 15:11:28 motivo volumio[1266]: at WriteWrap.onWriteComplete [as oncomplete] (node:internal/stream_base_commons:94:16) May 25 15:11:28 motivo volumio[1266]: at handleWriteReq (node:internal/stream_base_commons:58:21) May 25 15:11:28 motivo volumio[1266]: at writeGeneric (node:internal/stream_base_commons:149:15) May 25 15:11:28 motivo volumio[1266]: at Socket._writeGeneric (node:net:952:11) May 25 15:11:28 motivo volumio[1266]: at Socket._write (node:net:964:8) May 25 15:11:28 motivo volumio[1266]: at doWrite (node:internal/streams/writable:418:12) May 25 15:11:28 motivo volumio[1266]: at clearBuffer (node:internal/streams/writable:579:7) May 25 15:11:28 motivo volumio[1266]: at Writable.uncork (node:internal/streams/writable:358:7) May 25 15:11:28 motivo volumio[1266]: at ClientRequest._flushOutput (node:_http_outgoing:1151:10) May 25 15:11:28 motivo volumio[1266]: at ClientRequest._flush (node:_http_outgoing:1120:22) May 25 15:11:28 motivo volumio[1266]: at onSocketNT (node:_http_client:898:9) May 25 15:11:28 motivo volumio[1266]: at process.processTicksAndRejections (node:internal/process/task_queues:83:21) { May 25 15:11:28 motivo volumio[1266]: errno: -32, May 25 15:11:28 motivo volumio[1266]: code: 'EPIPE', May 25 15:11:28 motivo volumio[1266]: syscall: 'write' May 25 15:11:28 motivo volumio[1266]: } May 25 15:11:28 motivo volumio[1266]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 25 15:11:30 motivo volumio5-onboarding[1834]: time=2026-05-25T13:11:30.581Z level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn addr=1 chunks=1 index=0 tries=11 May 25 15:11:31 motivo volumio5-onboarding[1834]: time=2026-05-25T13:11:30.836Z level=ERROR msg="failed to send response" component=server dst="00:00:00:00:00:00%01,192.168.32.3:56174 @ 0x3001440" id=256529579 status=STATUS_OK error="no WebSocket connection found for address: 192.168.32.3:56174\npeer is gone" May 25 15:11:35 motivo systemd[1]: setdatetime-helper.service: Deactivated successfully. May 25 15:11:35 motivo systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. May 25 15:11:35 motivo systemd[1]: setdatetime-helper.service: Consumed 3.284s CPU time. May 25 15:11:37 motivo sudo[8910]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-05-25 15:10' May 25 15:11:37 motivo sudo[8910]: 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="9ccd1247f8cab3c5d64c23a96d243f6bfa34d032" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="e94c5b27ab2607d3918cd6a4973c240c1b2ce37e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="motivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat May 16 00:11:09 UTC 2026" VOLUMIO_VERSION="4.156" VOLUMIO_HARDWARE="cm4" VOLUMIO_DEVICENAME="CM4" VOLUMIO_VENDOR_MODEL="Volumio Motivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Motivo" VOLUMIO_HASH="67ebfb15187d4de64266b21b13da5443"