-- Logs begin at Sat 2025-05-10 09:19:31 CST, end at Sat 2025-05-10 10:11:24 CST. -- May 10 10:10:00 volumio volumio[970]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 10 10:10:04 volumio volumio[970]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 10 10:10:08 volumio volumio[970]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 10 10:10:12 volumio volumio[970]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 10 10:10:16 volumio volumio[970]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 10 10:10:20 volumio volumio[970]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 10 10:10:24 volumio volumio[970]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 10 10:10:28 volumio volumio[970]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 10 10:10:28 volumio volumio[970]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb May 10 10:10:28 volumio volumio[970]: verbose: ControllerMpd::sendMpdCommand update May 10 10:10:28 volumio volumio[970]: verbose: ControllerMpd::sendMpdCommand status May 10 10:10:28 volumio volumio[970]: info: May 10 10:10:28 volumio volumio[970]: ---------------------------- MPD announces state update: update May 10 10:10:28 volumio volumio[970]: info: sendMpdCommand update took 7 milliseconds May 10 10:10:28 volumio volumio[970]: info: ControllerMpd::getState May 10 10:10:28 volumio volumio[970]: verbose: ControllerMpd::sendMpdCommand status May 10 10:10:28 volumio volumio[970]: info: sendMpdCommand status took 21 milliseconds May 10 10:10:28 volumio volumio[970]: verbose: ControllerMpd::parseState May 10 10:10:28 volumio volumio[970]: info: Command Router : Notfying DB Updatetrue May 10 10:10:28 volumio volumio[970]: info: sendMpdCommand status took 105 milliseconds May 10 10:10:28 volumio volumio[970]: verbose: ControllerMpd::parseState May 10 10:10:28 volumio volumio[970]: info: ControllerMpd::pushState May 10 10:10:28 volumio volumio[970]: info: CoreCommandRouter::servicePushState May 10 10:10:28 volumio volumio[970]: info: CoreStateMachine::pushState May 10 10:10:28 volumio volumio[970]: info: CorePlayQueue::getTrack 0 May 10 10:10:28 volumio volumio[970]: info: CoreCommandRouter::volumioPushState May 10 10:10:28 volumio volumio[970]: info: CorePlayQueue::getTrack 0 May 10 10:10:28 volumio volumio[970]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 10 10:10:28 volumio volumio[970]: verbose: CURRENT POSITION 0 May 10 10:10:28 volumio volumio[970]: info: CoreStateMachine::syncState stateService stop May 10 10:10:28 volumio volumio[970]: info: CoreStateMachine::syncState currentStatus stop May 10 10:10:28 volumio volumio[970]: info: CoreStateMachine::pushState May 10 10:10:28 volumio volumio[970]: info: CorePlayQueue::getTrack 0 May 10 10:10:28 volumio volumio[970]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 10 10:10:28 volumio volumio[970]: info: CoreCommandRouter::volumioPushState May 10 10:10:28 volumio volumio[970]: info: No code May 10 10:10:28 volumio volumio[970]: info: CoreStateMachine::pushState May 10 10:10:28 volumio volumio[970]: info: CorePlayQueue::getTrack 0 May 10 10:10:28 volumio volumio[970]: info: CoreCommandRouter::volumioPushState May 10 10:10:28 volumio volumio[970]: info: ------------------------------ 156ms May 10 10:10:31 volumio volumio[970]: verbose: ControllerMpd::sendMpdCommand status May 10 10:10:31 volumio volumio[970]: info: May 10 10:10:31 volumio volumio[970]: ---------------------------- MPD announces state update: update May 10 10:10:31 volumio volumio[970]: info: ControllerMpd::getState May 10 10:10:31 volumio volumio[970]: verbose: ControllerMpd::sendMpdCommand status May 10 10:10:31 volumio volumio[970]: info: sendMpdCommand status took 3 milliseconds May 10 10:10:31 volumio volumio[970]: info: sendMpdCommand status took 2 milliseconds May 10 10:10:31 volumio volumio[970]: verbose: ControllerMpd::parseState May 10 10:10:31 volumio volumio[970]: info: Command Router : Notfying DB Updatefalse May 10 10:10:31 volumio volumio[970]: info: CoreCommandRouter::Close All Modals sent May 10 10:10:31 volumio volumio[970]: verbose: ControllerMpd::parseState May 10 10:10:31 volumio volumio[970]: info: ControllerMpd::pushState May 10 10:10:31 volumio volumio[970]: info: CoreCommandRouter::servicePushState May 10 10:10:31 volumio volumio[970]: info: CoreStateMachine::pushState May 10 10:10:31 volumio volumio[970]: info: CorePlayQueue::getTrack 0 May 10 10:10:31 volumio volumio[970]: info: CoreCommandRouter::volumioPushState May 10 10:10:31 volumio volumio[970]: info: CorePlayQueue::getTrack 0 May 10 10:10:31 volumio volumio[970]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 10 10:10:31 volumio volumio[970]: verbose: CURRENT POSITION 0 May 10 10:10:31 volumio volumio[970]: info: CoreStateMachine::syncState stateService stop May 10 10:10:31 volumio volumio[970]: info: CoreStateMachine::syncState currentStatus stop May 10 10:10:31 volumio volumio[970]: info: CoreStateMachine::pushState May 10 10:10:31 volumio volumio[970]: info: CorePlayQueue::getTrack 0 May 10 10:10:31 volumio volumio[970]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 10 10:10:31 volumio volumio[970]: info: CoreCommandRouter::volumioPushState May 10 10:10:31 volumio volumio[970]: info: No code May 10 10:10:31 volumio volumio[970]: info: CoreStateMachine::pushState May 10 10:10:31 volumio volumio[970]: info: CorePlayQueue::getTrack 0 May 10 10:10:31 volumio volumio[970]: info: CoreCommandRouter::volumioPushState May 10 10:10:31 volumio volumio[970]: info: ------------------------------ 118ms May 10 10:10:32 volumio volumio[970]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 10 10:10:36 volumio volumio[970]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 10 10:10:40 volumio volumio[970]: info: CoreCommandRouter::volumioGetState May 10 10:10:40 volumio volumio[970]: info: CorePlayQueue::getTrack 0 May 10 10:10:45 volumio volumio[970]: info: CoreCommandRouter::executeOnPlugin: mpd , lsInfo May 10 10:10:45 volumio volumio[970]: info: Saving local item undefined May 10 10:10:45 volumio volumio[970]: info: Pushing Favourites {"uri":"","favourite":false} May 10 10:10:45 volumio volumio[970]: info: Listing playlists May 10 10:10:56 volumio volumio[970]: Searching all installed plugins May 10 10:10:56 volumio volumio[970]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 10 10:10:56 volumio volumio[970]: info: CoreCommandRouter::executeOnPlugin: , search May 10 10:10:56 volumio volumio[970]: info: CoreCommandRouter::executeOnPlugin: mpd , search May 10 10:10:56 volumio volumio[970]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search May 10 10:10:56 volumio volumio[970]: info: CoreCommandRouter::executeOnPlugin: last_100 , search May 10 10:10:56 volumio volumio[970]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 May 10 10:10:56 volumio volumio[970]: info: CoreCommandRouter::executeOnPlugin: webradio , search May 10 10:10:57 volumio volumio[970]: (node:970) UnhandledPromiseRejectionWarning: Error: Start tag expected, '<' not found May 10 10:10:57 volumio volumio[970]: at Object.module.exports.fromXml (/volumio/node_modules/libxmljs/lib/document.js:168:21) May 10 10:10:57 volumio volumio[970]: at /volumio/app/plugins/music_service/webradio/index.js:949:31 May 10 10:10:57 volumio volumio[970]: at runMicrotasks () May 10 10:10:57 volumio volumio[970]: at processTicksAndRejections (internal/process/task_queues.js:93:5) May 10 10:10:57 volumio volumio[970]: (Use `node --trace-warnings ...` to show where the warning was created) May 10 10:10:57 volumio volumio[970]: (node:970) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 2) May 10 10:10:57 volumio volumio[970]: (node:970) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code. May 10 10:11:01 volumio volumio[970]: error: Search in plugin webradio timed out May 10 10:11:01 volumio volumio[970]: info: All search sources collected, pushing search results May 10 10:11:24 volumio volumio[970]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 10 10:11:24 volumio volumio[970]: Error: connect ETIMEDOUT 108.160.162.115:443 May 10 10:11:24 volumio volumio[970]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { May 10 10:11:24 volumio volumio[970]: errno: -110, May 10 10:11:24 volumio volumio[970]: code: 'ETIMEDOUT', May 10 10:11:24 volumio volumio[970]: syscall: 'connect', May 10 10:11:24 volumio volumio[970]: address: '108.160.162.115', May 10 10:11:24 volumio volumio[970]: port: 443 May 10 10:11:24 volumio volumio[970]: } May 10 10:11:24 volumio volumio[970]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 10 10:11:24 volumio sudo[3566]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-10 10:10 May 10 10:11:24 volumio sudo[3566]: 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="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 07:17:01 PM CEST" VOLUMIO_VERSION="3.742" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="2782e52360f70dfab079c82951ebbbb1"