-- Logs begin at Tue 2025-06-24 14:14:52 EDT, end at Tue 2025-06-24 14:17:08 EDT. -- Jun 24 14:16:03 volumio volumio[1309]: ......................................++++ Jun 24 14:16:03 volumio volumio[1309]: e is 65537 (0x010001) Jun 24 14:16:03 volumio volumio[1309]: writing RSA key Jun 24 14:16:09 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 24 14:16:09 volumio volumio[1086]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 21 Jun 24 14:16:09 volumio volumio[1086]: info: CoreCommandRouter::volumioGetState Jun 24 14:16:09 volumio volumio[1086]: info: CorePlayQueue::getTrack 0 Jun 24 14:16:12 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 24 14:16:12 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 24 14:16:12 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 24 14:16:12 volumio volumio-remote-updater[628]: No test mode Jun 24 14:16:12 volumio volumio-remote-updater[628]: No alpha test mode Jun 24 14:16:12 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jun 24 14:16:12 volumio volumio[1086]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Jun 24 14:16:12 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jun 24 14:16:14 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 14:16:14 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 14:16:14 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jun 24 14:16:14 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jun 24 14:16:14 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jun 24 14:16:14 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jun 24 14:16:14 volumio volumio[1086]: info: CoreCommandRouter::volumioGetBrowseSources Jun 24 14:16:14 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 24 14:16:15 volumio volumio[1086]: error: MyVolumio Plugin failed to authenticate in a timely fashion Jun 24 14:16:15 volumio volumio[1086]: info: Completed starting MyVolumio Plugin Jun 24 14:16:15 volumio volumio[1086]: [Metrics] CommandRouter: 41s 905.65ms Jun 24 14:16:15 volumio volumio[1086]: info: CoreCommandRouter::volumiosetStartupVolume Jun 24 14:16:15 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 24 14:16:15 volumio volumio[1086]: info: VolumeController:: Setting startup Volume 10 Jun 24 14:16:15 volumio volumio[1086]: info: VolumeController::SetAlsaVolume10 Jun 24 14:16:15 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 24 14:16:15 volumio volumio[1086]: info: CoreCommandRouter::Close All Modals sent Jun 24 14:16:15 volumio volumio[1086]: info: CoreCommandRouter::Close All Modals sent Jun 24 14:16:15 volumio volumio[1086]: info: CoreStateMachine::pushState Jun 24 14:16:15 volumio volumio[1086]: info: CorePlayQueue::getTrack 0 Jun 24 14:16:15 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 24 14:16:15 volumio volumio[1086]: info: CoreCommandRouter::volumioPushState Jun 24 14:16:16 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jun 24 14:16:16 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 24 14:16:16 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jun 24 14:16:22 volumio volumio[1086]: info: BOOT COMPLETED Jun 24 14:16:24 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 24 14:16:24 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 24 14:16:24 volumio volumio[1086]: info: Discovery: Getting this device information Jun 24 14:16:24 volumio volumio[1086]: info: CoreCommandRouter::volumioGetState Jun 24 14:16:24 volumio volumio[1086]: info: CorePlayQueue::getTrack 0 Jun 24 14:16:24 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 24 14:16:24 volumio ntpd[791]: Soliciting pool server 199.182.221.110 Jun 24 14:16:24 volumio ntpd[791]: Soliciting pool server 216.128.178.20 Jun 24 14:16:25 volumio ntpd[791]: Soliciting pool server 149.56.19.163 Jun 24 14:16:25 volumio ntpd[791]: Soliciting pool server 162.159.200.123 Jun 24 14:16:26 volumio ntpd[791]: Soliciting pool server 174.138.208.0 Jun 24 14:16:26 volumio ntpd[791]: Soliciting pool server 23.133.168.244 Jun 24 14:16:26 volumio ntpd[791]: Soliciting pool server 216.197.228.230 Jun 24 14:16:27 volumio ntpd[791]: Soliciting pool server 54.39.23.64 Jun 24 14:16:27 volumio ntpd[791]: Soliciting pool server 167.160.187.179 Jun 24 14:16:27 volumio ntpd[791]: Soliciting pool server 23.133.168.247 Jun 24 14:16:28 volumio ntpd[791]: Soliciting pool server 2001:470:b2de::1 Jun 24 14:16:28 volumio ntpd[791]: Soliciting pool server 158.69.48.17 Jun 24 14:16:28 volumio ntpd[791]: Soliciting pool server 206.108.0.131 Jun 24 14:16:28 volumio ntpd[791]: Soliciting pool server 216.6.2.70 Jun 24 14:16:29 volumio ntpd[791]: Soliciting pool server 216.232.132.102 Jun 24 14:16:29 volumio ntpd[791]: Soliciting pool server 162.159.200.1 Jun 24 14:16:29 volumio ntpd[791]: Soliciting pool server 167.114.93.151 Jun 24 14:16:30 volumio ntpd[791]: Soliciting pool server 142.4.192.253 Jun 24 14:16:30 volumio ntpd[791]: Soliciting pool server 158.69.247.84 Jun 24 14:16:30 volumio ntpd[791]: Soliciting pool server 207.210.46.249 Jun 24 14:16:32 volumio ntpd[791]: receive: Unexpected origin timestamp 0xec0569ff.d8f13958 does not match aorg 0000000000.00000000 from server@216.197.228.230 xmt 0xec056a00.7894803d Jun 24 14:16:34 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 24 14:16:34 volumio volumio[1086]: info: Preload queue cleared Jun 24 14:16:34 volumio volumio[1086]: info: CoreCommandRouter::volumioGetQueue Jun 24 14:16:34 volumio volumio[1086]: info: CoreStateMachine::getQueue Jun 24 14:16:34 volumio volumio[1086]: info: CorePlayQueue::getQueue Jun 24 14:16:54 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 24 14:16:54 volumio volumio[1086]: info: Preload queue cleared Jun 24 14:16:54 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 24 14:16:54 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 24 14:16:54 volumio volumio[1086]: info: Discovery: Getting this device information Jun 24 14:16:54 volumio volumio[1086]: info: CoreCommandRouter::volumioGetState Jun 24 14:16:54 volumio volumio[1086]: info: CorePlayQueue::getTrack 0 Jun 24 14:16:54 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 24 14:17:00 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 24 14:17:00 volumio volumio[1086]: info: Preload queue cleared Jun 24 14:17:02 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 24 14:17:02 volumio volumio[1086]: info: Preload queue cleared Jun 24 14:17:07 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 24 14:17:07 volumio volumio[1086]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 24 14:17:07 volumio volumio[1086]: TypeError: Cannot read property 'length' of undefined Jun 24 14:17:07 volumio volumio[1086]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Jun 24 14:17:07 volumio volumio[1086]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Jun 24 14:17:07 volumio volumio[1086]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Jun 24 14:17:07 volumio volumio[1086]: at Parser.emit (events.js:315:20) Jun 24 14:17:07 volumio volumio[1086]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Jun 24 14:17:07 volumio volumio[1086]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Jun 24 14:17:07 volumio volumio[1086]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Jun 24 14:17:07 volumio volumio[1086]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Jun 24 14:17:07 volumio volumio[1086]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Jun 24 14:17:07 volumio volumio[1086]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Jun 24 14:17:07 volumio volumio[1086]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Jun 24 14:17:07 volumio volumio[1086]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Jun 24 14:17:07 volumio volumio[1086]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Jun 24 14:17:07 volumio volumio[1086]: at IncomingMessage.emit (events.js:327:22) Jun 24 14:17:07 volumio volumio[1086]: at endReadableNT (internal/streams/readable.js:1327:12) Jun 24 14:17:07 volumio volumio[1086]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jun 24 14:17:07 volumio volumio[1086]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 24 14:17:08 volumio sudo[1538]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-24 14:16 Jun 24 14:17:08 volumio sudo[1538]: 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="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 10 Jun 2025 04:52:53 PM CEST" VOLUMIO_VERSION="3.816" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="a72866a0de4045751d03a035de6290e1"