Oct 02 16:23:00 volumio-nova systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Oct 02 16:23:00 volumio-nova systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Oct 02 16:23:00 volumio-nova systemd[1]: setdatetime-helper.service: Deactivated successfully. Oct 02 16:23:00 volumio-nova systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Oct 02 16:23:00 volumio-nova systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Oct 02 16:23:00 volumio-nova systemd[1]: dpkg-db-backup.service: Deactivated successfully. Oct 02 16:23:00 volumio-nova systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Oct 02 16:23:00 volumio-nova volumio[1261]: error: MyVolumio Plugin failed to start in a timely fashion Oct 02 16:23:00 volumio-nova volumio[1261]: [Metrics] CommandRouter: 43s 458.81ms Oct 02 16:23:00 volumio-nova volumio[1261]: info: CoreCommandRouter::volumiosetStartupVolume Oct 02 16:23:00 volumio-nova volumio[1261]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 02 16:23:00 volumio-nova ntpd[1059]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Oct 02 16:23:00 volumio-nova ntpd[1059]: DNS: dns_check: DNS error: -11, System error Oct 02 16:23:00 volumio-nova ntpd[1059]: DNS: dns_take_status: 0.debian.pool.ntp.org=>error, 12 Oct 02 16:23:00 volumio-nova volumio[1261]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 02 16:23:00 volumio-nova volumio[1261]: info: CoreCommandRouter::Close All Modals sent Oct 02 16:23:00 volumio-nova volumio[1261]: info: CoreCommandRouter::Close All Modals sent Oct 02 16:23:01 volumio-nova volumio[1261]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Oct 02 16:23:01 volumio-nova volumio[1261]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 02 16:23:01 volumio-nova volumio[1261]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Oct 02 16:23:02 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:02-03:00" level=debug msg="new websocket client" Oct 02 16:23:02 volumio-nova volumio[1261]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 02 16:23:02 volumio-nova volumio[1261]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 02 16:23:02 volumio-nova volumio[1261]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 02 16:23:02 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:02-03:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 02 16:23:02 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:02-03:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 02 16:23:02 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:02-03:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 02 16:23:02 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:02-03:00" level=info msg="zeroconf server listening on port 44223" Oct 02 16:23:02 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:02-03:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Oct 02 16:23:02 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:02-03:00" level=info msg="loading previously persisted zeroconf credentials" username="31*********************07" Oct 02 16:23:03 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:03-03:00" level=debug msg="obtained new client token: AAH7RMsVLjnz0eQBnOJKjjn+03PQvhGpQwX/8SBiNf0UPci9hft41yKyuQSoSHbRn1ZNDVok/Hv4MyIUlXfluUFxM9HVBIV5L5QqpWDzPmnz6tk3ZB1gpvp/qOynL5P14F5jeu3tj5ZFZasknpnTwBnzSr30g4sWnAjb0dJHIoFSzh1YqGFIom3gKerLduplT5Ef+0SC0922nYHpc/unmfWQ3MpBLuMtDA+RX7XVPFM6G0x/VuYs7ps=" Oct 02 16:23:03 volumio-nova volumio[1261]: info: Connection to go-librespot Websocket established Oct 02 16:23:03 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:03-03:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Oct 02 16:23:03 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:03-03:00" level=debug msg="avahi service \"Volumio-nova\" established" Oct 02 16:23:03 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:03-03:00" level=debug msg="completed keyexchange" Oct 02 16:23:03 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:03-03:00" level=debug msg="completed challenge" Oct 02 16:23:03 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:03-03:00" level=info msg="authenticated AP" username="31*********************07" Oct 02 16:23:04 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:04-03:00" level=info msg="authenticated Login5" username="31*********************07" Oct 02 16:23:04 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:04-03:00" level=debug msg="initializing zeroconf session" username="31*********************07" Oct 02 16:23:04 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:04-03:00" level=debug msg="connected to guc3-dealer.spotify.com:443" Oct 02 16:23:04 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:04-03:00" level=trace msg="starting accesspoint recv loop" Oct 02 16:23:04 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:04-03:00" level=trace msg="starting dealer recv loop" Oct 02 16:23:04 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:04-03:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Oct 02 16:23:04 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:04-03:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Oct 02 16:23:04 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:04-03:00" level=debug msg="received connection id: YzY1ZDViNGMtMmI2...RkFCQzNGQUE4Ng==" Oct 02 16:23:04 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:04-03:00" level=debug msg="put connect state because NEW_DEVICE" Oct 02 16:23:04 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:04-03:00" level=trace msg="emitting websocket event: playback_ready" Oct 02 16:23:04 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:04-03:00" level=debug msg="update volume requested to 62914/65535" Oct 02 16:23:04 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:04-03:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Oct 02 16:23:04 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:04-03:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Oct 02 16:23:04 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:04-03:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Oct 02 16:23:05 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:05-03:00" level=debug msg="put connect state because VOLUME_CHANGED" Oct 02 16:23:05 volumio-nova go-librespot[1999]: time="2026-10-02T16:23:05-03:00" level=trace msg="emitting websocket event: volume" Oct 02 16:23:05 volumio-nova kernel: xhci_hcd 0000:01:00.0: ERROR Transfer event for disabled endpoint slot 4 ep 1 Oct 02 16:23:05 volumio-nova kernel: xhci_hcd 0000:01:00.0: @0000000428d18ce0 00000000 00000000 0e000000 04028001 Oct 02 16:23:10 volumio-nova volumio[1261]: info: Discovery: A device disappeared from network Oct 02 16:23:10 volumio-nova volumio[1261]: info: Getting Spotify volume Oct 02 16:23:10 volumio-nova volumio[1261]: info: BOOT COMPLETED Oct 02 16:23:10 volumio-nova volumio[1261]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 02 16:23:10 volumio-nova volumio[1261]: Error [ERR_INTERNAL_ASSERTION]: This is caused by either a bug in Node.js or incorrect usage of Node.js internals. Oct 02 16:23:10 volumio-nova volumio[1261]: Please open an issue with this stack trace at https://github.com/nodejs/node/issues Oct 02 16:23:10 volumio-nova volumio[1261]: at new NodeError (node:internal/errors:405:5) Oct 02 16:23:10 volumio-nova volumio[1261]: at assert (node:internal/assert:14:11) Oct 02 16:23:10 volumio-nova volumio[1261]: at internalConnectMultiple (node:net:1118:3) Oct 02 16:23:10 volumio-nova volumio[1261]: at Timeout.internalConnectMultipleTimeout (node:net:1687:3) Oct 02 16:23:10 volumio-nova volumio[1261]: at listOnTimeout (node:internal/timers:575:11) Oct 02 16:23:10 volumio-nova volumio[1261]: at process.processTimers (node:internal/timers:514:7) { Oct 02 16:23:10 volumio-nova volumio[1261]: code: 'ERR_INTERNAL_ASSERTION' Oct 02 16:23:10 volumio-nova volumio[1261]: } Oct 02 16:23:10 volumio-nova volumio[1261]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 02 16:23:13 volumio-nova systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 5. Oct 02 16:23:13 volumio-nova systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Oct 02 16:23:13 volumio-nova systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Oct 02 16:23:13 volumio-nova upmpdcli[2086]: Could not open config: /tmp/upmpdcli.conf Oct 02 16:23:13 volumio-nova systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Oct 02 16:23:13 volumio-nova systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Oct 02 16:23:16 volumio-nova sudo[2089]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-02 16:22' Oct 02 16:23:16 volumio-nova sudo[2089]: 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="ebd772339e193fb4b3a98c68e63a0009e72d6f27" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0a52c1fb90959ba1872a2fb0225e56fe615b19ac" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon Sep 14 07:39:23 UTC 2026" VOLUMIO_VERSION="4.204" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="915e71dafc26fd850574d238b4f947d5"