-- Logs begin at Mon 2025-09-01 17:37:53 BST, end at Mon 2025-09-01 18:22:04 BST. -- Sep 01 18:21:04 volumio volumio[1285]: info: CorePlayQueue::getTrack 8 Sep 01 18:21:04 volumio volumio[1285]: info: CorePlayQueue::getTrack 9 Sep 01 18:21:04 volumio volumio[1285]: info: Prefetching next song Sep 01 18:21:04 volumio volumio[1285]: info: DOING PREFETCH IN MPD Sep 01 18:21:04 volumio volumio[1285]: verbose: ControllerMpd::sendMpdCommand add "NAS/NVMeMusic/MUSIC - FLAC/Rock/Bonnie Raitt/Bonnie Raitt - Luck of the draw - FLAC/10 - Slow Ride.flac" Sep 01 18:21:04 volumio volumio[1285]: info: Sep 01 18:21:04 volumio volumio[1285]: ---------------------------- MPD announces system playlist update Sep 01 18:21:04 volumio volumio[1285]: info: Ignoring MPD Status Update Sep 01 18:21:04 volumio volumio[1285]: info: sendMpdCommand add "NAS/NVMeMusic/MUSIC - FLAC/Rock/Bonnie Raitt/Bonnie Raitt - Luck of the draw - FLAC/10 - Slow Ride.flac" took 2 milliseconds Sep 01 18:21:04 volumio volumio[1285]: verbose: ControllerMpd::sendMpdCommand consume 1 Sep 01 18:21:04 volumio volumio[1285]: info: ------------------------------ 0ms Sep 01 18:21:04 volumio volumio[1285]: info: sendMpdCommand consume 1 took 0 milliseconds Sep 01 18:21:09 volumio volumio[1285]: info: CoreStateMachine::startPlaybackTimer Sep 01 18:21:09 volumio volumio[1285]: info: CorePlayQueue::getTrack 9 Sep 01 18:21:09 volumio volumio[1285]: info: CoreStateMachine::pushState Sep 01 18:21:09 volumio volumio[1285]: info: CorePlayQueue::getTrack 9 Sep 01 18:21:09 volumio volumio[1285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 01 18:21:09 volumio volumio[1285]: info: CoreCommandRouter::volumioPushState Sep 01 18:21:09 volumio volumio[1285]: info: MRS: Pushing multiroomSync output update for this device Sep 01 18:21:09 volumio volumio[1285]: info: MRS: Pushing multiroomSync output Sep 01 18:21:09 volumio volumio[1285]: info: CoreCommandRouter::volumioGetState Sep 01 18:21:09 volumio volumio[1285]: info: CorePlayQueue::getTrack 9 Sep 01 18:21:09 volumio volumio[1285]: info: Sep 01 18:21:09 volumio volumio[1285]: ---------------------------- MPD announces system playlist update Sep 01 18:21:09 volumio volumio[1285]: info: Ignoring MPD Status Update Sep 01 18:21:09 volumio volumio[1285]: info: Sep 01 18:21:09 volumio volumio[1285]: ---------------------------- MPD announces state update: player Sep 01 18:21:09 volumio volumio[1285]: info: ControllerMpd::getState Sep 01 18:21:09 volumio volumio[1285]: verbose: ControllerMpd::sendMpdCommand status Sep 01 18:21:09 volumio volumio[1285]: info: ------------------------------ 1ms Sep 01 18:21:09 volumio volumio[1285]: info: sendMpdCommand status took 0 milliseconds Sep 01 18:21:09 volumio volumio[1285]: verbose: ControllerMpd::parseState Sep 01 18:21:09 volumio volumio[1285]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 01 18:21:09 volumio volumio[1285]: info: sendMpdCommand playlistinfo took 1 milliseconds Sep 01 18:21:09 volumio volumio[1285]: verbose: ControllerMpd::parseTrackInfo Sep 01 18:21:09 volumio volumio[1285]: info: ControllerMpd::pushState Sep 01 18:21:09 volumio volumio[1285]: info: CoreCommandRouter::servicePushState Sep 01 18:21:09 volumio volumio[1285]: info: CorePlayQueue::getTrack 9 Sep 01 18:21:09 volumio volumio[1285]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":239,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"712 Kbps","isStreaming":false,"title":"Slow Ride","artist":"Bonnie Raitt","album":"Luck of the Draw","uri":"NAS/NVMeMusic/MUSIC - FLAC/Rock/Bonnie Raitt/Bonnie Raitt - Luck of the draw - FLAC/10 - Slow Ride.flac","trackType":"flac"} Sep 01 18:21:09 volumio volumio[1285]: verbose: CURRENT POSITION 9 Sep 01 18:21:09 volumio volumio[1285]: info: CoreStateMachine::syncState stateService play Sep 01 18:21:09 volumio volumio[1285]: info: CoreStateMachine::syncState currentStatus play Sep 01 18:21:09 volumio volumio[1285]: info: Received an update from plugin. extracting info from payload Sep 01 18:21:09 volumio volumio[1285]: info: CoreStateMachine::pushState Sep 01 18:21:09 volumio volumio[1285]: info: CorePlayQueue::getTrack 9 Sep 01 18:21:09 volumio volumio[1285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 01 18:21:09 volumio volumio[1285]: info: CoreCommandRouter::volumioPushState Sep 01 18:21:09 volumio volumio[1285]: info: MRS: Pushing multiroomSync output update for this device Sep 01 18:21:09 volumio volumio[1285]: info: MRS: Pushing multiroomSync output Sep 01 18:21:09 volumio volumio[1285]: info: CoreCommandRouter::volumioGetState Sep 01 18:21:09 volumio volumio[1285]: info: CorePlayQueue::getTrack 9 Sep 01 18:21:09 volumio volumio[1285]: info: CoreStateMachine::pushState Sep 01 18:21:09 volumio volumio[1285]: info: CorePlayQueue::getTrack 9 Sep 01 18:21:09 volumio volumio[1285]: info: CoreCommandRouter::volumioPushState Sep 01 18:21:09 volumio volumio[1285]: info: MRS: Pushing multiroomSync output update for this device Sep 01 18:21:09 volumio volumio[1285]: info: MRS: Pushing multiroomSync output Sep 01 18:21:09 volumio volumio[1285]: info: CoreCommandRouter::volumioGetState Sep 01 18:21:09 volumio volumio[1285]: info: CorePlayQueue::getTrack 9 Sep 01 18:21:09 volumio volumio[1285]: info: ------------------------------ 9ms Sep 01 18:21:37 volumio ntpd[998]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Sep 01 18:21:43 volumio ntpd[998]: Soliciting pool server 2a00:da00:f411:2900::123 Sep 01 18:21:47 volumio ntpd[998]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Sep 01 18:21:47 volumio ntpd[998]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Sep 01 18:21:58 volumio dhcpcd[1138]: eth0: carrier acquired Sep 01 18:21:58 volumio kernel: macb 1f00100000.ethernet eth0: Link is Up - 1Gbps/Full - flow control off Sep 01 18:21:58 volumio dhcpcd[1138]: eth0: IAID 67:6b:09:42 Sep 01 18:21:58 volumio dhcpcd[1138]: eth0: soliciting an IPv6 router Sep 01 18:21:59 volumio dhcpcd[1138]: eth0: rebinding lease of 192.168.1.108 Sep 01 18:21:59 volumio dhcpcd[1138]: eth0: probing address 192.168.1.108/24 Sep 01 18:21:59 volumio ifplugd(eth0)[985]: Link beat detected. Sep 01 18:21:59 volumio ifplugd(eth0)[985]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Sep 01 18:21:59 volumio dhcpcd[8688]: sending commands to master dhcpcd process Sep 01 18:21:59 volumio ifplugd(eth0)[985]: client: sending commands to master dhcpcd process Sep 01 18:21:59 volumio dhcpcd[1197]: control command: /sbin/dhcpcd eth0 Sep 01 18:21:59 volumio dhcpcd[1197]: eth0: carrier acquired Sep 01 18:21:59 volumio dhcpcd[1197]: eth0: IAID 67:6b:09:42 Sep 01 18:21:59 volumio dhcpcd[1197]: eth0: rebinding lease of 192.168.1.108 Sep 01 18:21:59 volumio ifplugd(eth0)[985]: Program executed successfully. Sep 01 18:21:59 volumio dhcpcd[1197]: eth0: soliciting an IPv6 router Sep 01 18:21:59 volumio dhcpcd[1197]: eth0: probing address 192.168.1.108/24 Sep 01 18:22:03 volumio dhcpcd[1138]: eth0: leased 192.168.1.108 for 86400 seconds Sep 01 18:22:03 volumio dhcpcd[1138]: eth0: adding route to 192.168.1.0/24 Sep 01 18:22:03 volumio dhcpcd[1138]: eth0: adding default route via 192.168.1.254 Sep 01 18:22:03 volumio avahi-daemon[847]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.108. Sep 01 18:22:03 volumio avahi-daemon[847]: New relevant interface eth0.IPv4 for mDNS. Sep 01 18:22:03 volumio avahi-daemon[847]: Registering new address record for 192.168.1.108 on eth0.IPv4. Sep 01 18:22:04 volumio volumio[1285]: info: Discovery: adding aad6d159-2730-42c5-8f40-ef090dc4f39a Sep 01 18:22:04 volumio volumio[1285]: info: Discovery: Found device Volumio Sep 01 18:22:04 volumio volumio[1285]: info: CoreCommandRouter::volumioGetState Sep 01 18:22:04 volumio volumio[1285]: info: CorePlayQueue::getTrack 9 Sep 01 18:22:04 volumio volumio[1285]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 18:22:04 volumio volumio[1285]: Error: The value NaN is not a number Sep 01 18:22:04 volumio volumio[1285]: at Config.forceToType (/volumio/node_modules/v-conf/index.js:322:20) Sep 01 18:22:04 volumio volumio[1285]: at Config.set (/volumio/node_modules/v-conf/index.js:153:25) Sep 01 18:22:04 volumio volumio[1285]: at ControllerVolumioDiscovery.updateMultiroomDevice (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:323:25) Sep 01 18:22:04 volumio volumio[1285]: at ControllerVolumioDiscovery.connectToRemoteVolumio (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:273:10) Sep 01 18:22:04 volumio volumio[1285]: at Browser. (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:192:12) Sep 01 18:22:04 volumio volumio[1285]: at Browser.emit (events.js:315:20) Sep 01 18:22:04 volumio volumio[1285]: at on_resolver_done (/volumio/node_modules/mdns/lib/browser.js:31:14) Sep 01 18:22:04 volumio volumio[1285]: at next (/volumio/node_modules/mdns/lib/browser.js:106:7) Sep 01 18:22:04 volumio volumio[1285]: at Array.makeAddressesUnique (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:177:5) Sep 01 18:22:04 volumio volumio[1285]: at next (/volumio/node_modules/mdns/lib/browser.js:109:21) Sep 01 18:22:04 volumio volumio[1285]: at /volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:160:11 Sep 01 18:22:04 volumio volumio[1285]: at getaddrinfo_complete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:108:7) Sep 01 18:22:04 volumio volumio[1285]: at GetAddrInfoReqWrap.oncomplete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:120:9) Sep 01 18:22:04 volumio volumio[1285]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 18:22:04 volumio ntpd[998]: Listen normally on 4 eth0 192.168.1.108:123 Sep 01 18:22:04 volumio ntpd[998]: new interface(s) found: waking up resolver Sep 01 18:22:04 volumio sudo[8750]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-01 18:21 Sep 01 18:22:04 volumio sudo[8750]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="29866754e5f1d7e4d0f581c10d9f22852f6f21db" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:25:36 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="cf6e14681b2ecbbdc9a62186b0f3114c"