-- Logs begin at Fri 2025-06-13 18:49:31 CEST, end at Fri 2025-06-13 18:52:07 CEST. -- Jun 13 18:51:03 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 13 18:51:03 volumio volumio[1119]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 25 Jun 13 18:51:03 volumio volumio[1119]: info: CoreCommandRouter::volumioGetState Jun 13 18:51:03 volumio volumio[1119]: info: CorePlayQueue::getTrack 0 Jun 13 18:51:04 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 13 18:51:04 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 13 18:51:04 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 13 18:51:04 volumio volumio-remote-updater[628]: No test mode Jun 13 18:51:04 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jun 13 18:51:04 volumio volumio-remote-updater[628]: No alpha test mode Jun 13 18:51:04 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 13 18:51:04 volumio volumio[1119]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Jun 13 18:51:04 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jun 13 18:51:07 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 13 18:51:08 volumio ntpd[776]: Soliciting pool server 188.34.165.100 Jun 13 18:51:08 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 13 18:51:08 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 13 18:51:08 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jun 13 18:51:08 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jun 13 18:51:08 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jun 13 18:51:08 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jun 13 18:51:08 volumio volumio[1119]: info: CoreCommandRouter::volumioGetBrowseSources Jun 13 18:51:08 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 13 18:51:10 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 13 18:51:11 volumio ntpd[776]: Soliciting pool server 131.188.3.220 Jun 13 18:51:11 volumio ntpd[776]: Soliciting pool server 176.9.44.212 Jun 13 18:51:11 volumio volumio[1119]: error: MyVolumio Plugin failed to authenticate in a timely fashion Jun 13 18:51:11 volumio volumio[1119]: info: Completed starting MyVolumio Plugin Jun 13 18:51:11 volumio volumio[1119]: [Metrics] CommandRouter: 50s 33.88ms Jun 13 18:51:11 volumio volumio[1119]: info: CoreCommandRouter::volumiosetStartupVolume Jun 13 18:51:11 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 13 18:51:11 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 13 18:51:11 volumio volumio[1119]: info: CoreCommandRouter::Close All Modals sent Jun 13 18:51:11 volumio volumio[1119]: info: CoreCommandRouter::Close All Modals sent Jun 13 18:51:12 volumio ntpd[776]: Soliciting pool server 128.140.109.119 Jun 13 18:51:12 volumio ntpd[776]: Soliciting pool server 148.251.5.46 Jun 13 18:51:12 volumio ntpd[776]: Soliciting pool server 136.243.177.133 Jun 13 18:51:12 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jun 13 18:51:12 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 13 18:51:12 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jun 13 18:51:13 volumio volumio[1332]: ...............................................................................................................................++++ Jun 13 18:51:13 volumio ntpd[776]: Soliciting pool server 94.130.184.193 Jun 13 18:51:13 volumio ntpd[776]: Soliciting pool server 107.189.12.98 Jun 13 18:51:13 volumio ntpd[776]: Soliciting pool server 185.232.69.65 Jun 13 18:51:14 volumio ntpd[776]: Soliciting pool server 2a01:4f9:c012:5e8a::1 Jun 13 18:51:14 volumio ntpd[776]: Soliciting pool server 144.76.76.107 Jun 13 18:51:14 volumio ntpd[776]: Soliciting pool server 194.50.19.204 Jun 13 18:51:15 volumio ntpd[776]: Soliciting pool server 5.189.151.39 Jun 13 18:51:15 volumio ntpd[776]: Soliciting pool server 31.209.85.242 Jun 13 18:51:19 volumio ntpd[776]: receive: Unexpected origin timestamp 0xebf6d586.7badcc33 does not match aorg 0000000000.00000000 from server@136.243.177.133 xmt 0xebf6d587.3be682b8 Jun 13 18:51:19 volumio ntpd[776]: receive: Unexpected origin timestamp 0xebf6d586.7bb3b812 does not match aorg 0000000000.00000000 from server@131.188.3.220 xmt 0xebf6d587.3cb8b55c Jun 13 18:51:19 volumio ntpd[776]: receive: Unexpected origin timestamp 0xebf6d586.7baaa598 does not match aorg 0000000000.00000000 from server@107.189.12.98 xmt 0xebf6d587.3b7f8aa0 Jun 13 18:51:19 volumio volumio[1119]: info: BOOT COMPLETED Jun 13 18:51:25 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 13 18:51:27 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 13 18:51:31 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 13 18:51:33 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 13 18:51:37 volumio volumio[1332]: ......................................................................................++++ Jun 13 18:51:37 volumio volumio[1332]: e is 65537 (0x010001) Jun 13 18:51:37 volumio volumio[1332]: writing RSA key Jun 13 18:51:39 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 13 18:51:40 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 13 18:51:41 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 13 18:51:46 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 13 18:51:48 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 13 18:51:50 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 13 18:51:50 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 13 18:51:53 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 13 18:51:55 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 13 18:51:56 volumio volumio[1119]: error: Did not get expected response from server:{"Envelope":{"$":{"xmlns:s":"http://schemas.xmlsoap.org/soap/envelope/","s:encodingStyle":"http://schemas.xmlsoap.org/soap/encoding/"},"Body":[{"Fault":[{"faultcode":[{"_":"s:Client"}],"faultstring":[{"_":"UPnPError"}],"detail":[{"UPnPError":[{"$":{"xmlns":"urn:schemas-upnp-org:control-1-0"},"errorCode":[{"_":"720"}],"errorDescription":[{"_":"cannot process the request"}]}]}]}]}]}} Jun 13 18:51:56 volumio volumio[1119]: info: Preload queue cleared Jun 13 18:51:56 volumio volumio[1119]: info: Preload queue cleared Jun 13 18:51:56 volumio volumio[1119]: info: Preload queue cleared Jun 13 18:51:56 volumio volumio[1119]: info: Preload queue cleared Jun 13 18:51:56 volumio volumio[1119]: info: Preload queue cleared Jun 13 18:51:56 volumio volumio[1119]: info: Preload queue cleared Jun 13 18:51:56 volumio volumio[1119]: info: Preload queue cleared Jun 13 18:51:57 volumio volumio[1119]: info: Preload queue cleared Jun 13 18:51:57 volumio volumio[1119]: info: Preload queue cleared Jun 13 18:51:57 volumio volumio[1119]: info: Preload queue cleared Jun 13 18:51:57 volumio volumio[1119]: info: Preload queue cleared Jun 13 18:51:57 volumio volumio[1119]: info: Preload queue cleared Jun 13 18:51:57 volumio volumio[1119]: info: Preload queue cleared Jun 13 18:51:57 volumio volumio[1119]: info: Preload queue cleared Jun 13 18:51:57 volumio volumio[1119]: info: Preload queue cleared Jun 13 18:51:57 volumio volumio[1119]: info: Preload queue cleared Jun 13 18:52:00 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 13 18:52:00 volumio volumio[1119]: info: Preload queue cleared Jun 13 18:52:01 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 13 18:52:01 volumio volumio[1119]: info: Preload queue cleared Jun 13 18:52:03 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 13 18:52:04 volumio volumio[1119]: info: Preload queue cleared Jun 13 18:52:06 volumio volumio[1119]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 13 18:52:06 volumio volumio[1119]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 13 18:52:06 volumio volumio[1119]: TypeError: Cannot read property 'length' of undefined Jun 13 18:52:06 volumio volumio[1119]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Jun 13 18:52:06 volumio volumio[1119]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Jun 13 18:52:06 volumio volumio[1119]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Jun 13 18:52:06 volumio volumio[1119]: at Parser.emit (events.js:315:20) Jun 13 18:52:06 volumio volumio[1119]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Jun 13 18:52:06 volumio volumio[1119]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Jun 13 18:52:06 volumio volumio[1119]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Jun 13 18:52:06 volumio volumio[1119]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Jun 13 18:52:06 volumio volumio[1119]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Jun 13 18:52:06 volumio volumio[1119]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Jun 13 18:52:06 volumio volumio[1119]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Jun 13 18:52:06 volumio volumio[1119]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Jun 13 18:52:06 volumio volumio[1119]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Jun 13 18:52:06 volumio volumio[1119]: at IncomingMessage.emit (events.js:327:22) Jun 13 18:52:06 volumio volumio[1119]: at endReadableNT (internal/streams/readable.js:1327:12) Jun 13 18:52:06 volumio volumio[1119]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jun 13 18:52:06 volumio volumio[1119]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 13 18:52:07 volumio sudo[1596]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-13 18:51 Jun 13 18:52:07 volumio sudo[1596]: 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"