Oct 16 17:44:03 volumio volumio[1429]: info: Tunnel connection is inactive, restarting it Oct 16 17:44:03 volumio volumio[1429]: info: Starting Tunnel 1 Oct 16 17:44:03 volumio volumio[1429]: info: Starting Tunnel Connection Checker Oct 16 17:44:03 volumio sudo[7843]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Oct 16 17:44:03 volumio sudo[7843]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:44:03 volumio autossh[7569]: received signal to exit (15) Oct 16 17:44:03 volumio systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel... Oct 16 17:44:03 volumio systemd[1]: sshtunnel.service: Deactivated successfully. Oct 16 17:44:03 volumio systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Oct 16 17:44:03 volumio systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Oct 16 17:44:03 volumio sudo[7843]: pam_unix(sudo:session): session closed for user root Oct 16 17:44:03 volumio volumio[1429]: info: Remote SSH Started Oct 16 17:44:03 volumio autossh[7846]: port set to 0, monitoring disabled Oct 16 17:44:03 volumio autossh[7846]: starting ssh (count 1) Oct 16 17:44:03 volumio autossh[7846]: ssh child pid is 7850 Oct 16 17:44:03 volumio volumio[1429]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Oct 16 17:44:03 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Oct 16 17:44:03 volumio volumio[1429]: info: CorePlayQueue::getTrack 11 Oct 16 17:44:03 volumio volumiossh-tunnel[7850]: Warning: Permanently added '[eu6.myvolumio.org]:2222' (RSA) to the list of known hosts. Oct 16 17:44:43 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Oct 16 17:44:44 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Oct 16 17:44:44 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Oct 16 17:44:56 volumio volumio5-onboarding[1669]: time=2026-10-16T17:44:56.538+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.133:43492,00:00:00:00:00:00%01 @ 0x14012c0" latency=-1.504604869s timeout=10s Oct 16 17:44:56 volumio volumio5-onboarding[1669]: time=2026-10-16T17:44:56.619+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.133:43492,00:00:00:00:00:00%01 @ 0x14012c0" latency=-1.504604869s timeout=10s endpoint=http://pushupdates.volumio.org duration=80.997978ms Oct 16 17:44:56 volumio volumio5-onboarding[1669]: time=2026-10-16T17:44:56.634+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.133:43492,00:00:00:00:00:00%01 @ 0x14012c0" latency=-1.504604869s timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=95.859108ms Oct 16 17:44:56 volumio volumio5-onboarding[1669]: time=2026-10-16T17:44:56.697+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.133:43492,00:00:00:00:00:00%01 @ 0x14012c0" latency=-1.504604869s timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=158.134193ms Oct 16 17:44:56 volumio volumio5-onboarding[1669]: time=2026-10-16T17:44:56.697+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.133:43492,00:00:00:00:00:00%01 @ 0x14012c0" latency=-1.504604869s timeout=10s endpoint=http://cddb.volumio.org duration=157.640651ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 16 17:44:56 volumio volumio5-onboarding[1669]: time=2026-10-16T17:44:56.697+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.133:43492,00:00:00:00:00:00%01 @ 0x14012c0" latency=-1.504604869s timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=158.608994ms Oct 16 17:44:56 volumio volumio5-onboarding[1669]: time=2026-10-16T17:44:56.772+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.133:43492,00:00:00:00:00:00%01 @ 0x14012c0" latency=-1.504604869s timeout=10s endpoint=https://www.googleapis.com duration=233.217759ms Oct 16 17:44:56 volumio volumio5-onboarding[1669]: time=2026-10-16T17:44:56.786+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.133:43492,00:00:00:00:00:00%01 @ 0x14012c0" latency=-1.504604869s timeout=10s endpoint=https://securetoken.googleapis.com duration=246.973546ms Oct 16 17:44:56 volumio volumio5-onboarding[1669]: time=2026-10-16T17:44:56.789+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.133:43492,00:00:00:00:00:00%01 @ 0x14012c0" latency=-1.504604869s timeout=10s endpoint=https://functions.volumio.cloud duration=249.648461ms Oct 16 17:44:56 volumio volumio5-onboarding[1669]: time=2026-10-16T17:44:56.791+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.133:43492,00:00:00:00:00:00%01 @ 0x14012c0" latency=-1.504604869s timeout=10s endpoint=https://functions.volumio.cloud duration=251.352885ms Oct 16 17:44:56 volumio volumio5-onboarding[1669]: time=2026-10-16T17:44:56.820+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.133:43492,00:00:00:00:00:00%01 @ 0x14012c0" latency=-1.504604869s timeout=10s endpoint=https://google.com duration=280.639605ms Oct 16 17:44:56 volumio volumio5-onboarding[1669]: time=2026-10-16T17:44:56.824+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.133:43492,00:00:00:00:00:00%01 @ 0x14012c0" latency=-1.504604869s timeout=10s endpoint=https://myvolumio.firebaseio.com duration=284.92874ms Oct 16 17:44:56 volumio volumio5-onboarding[1669]: time=2026-10-16T17:44:56.842+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.133:43492,00:00:00:00:00:00%01 @ 0x14012c0" latency=-1.504604869s timeout=10s endpoint=http://plugins.volumio.org duration=302.962087ms Oct 16 17:44:56 volumio volumio5-onboarding[1669]: time=2026-10-16T17:44:56.949+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.133:43492,00:00:00:00:00:00%01 @ 0x14012c0" latency=-1.504604869s timeout=10s endpoint=https://database.volumio.cloud duration=410.333383ms Oct 16 17:44:57 volumio volumio[1429]: verbose: New Socket.io Connection to 192.168.1.136 from 192.168.1.133 UA: Mozilla/5.0 (Linux; Android 17; Pixel 7a Build/CP3A.261005.002.A1; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/153.0.8010.36 Mobile Safari/537.36 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 8 Oct 16 17:44:57 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 16 17:44:57 volumio volumio[1429]: info: CoreCommandRouter::volumioGetVisibleSources Oct 16 17:44:57 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 17:44:57 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Oct 16 17:44:57 volumio volumio[1429]: info: CorePlayQueue::getTrack 11 Oct 16 17:44:57 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 16 17:44:57 volumio volumio[1429]: info: CoreCommandRouter::volumioGetQueue Oct 16 17:44:57 volumio volumio[1429]: info: CoreStateMachine::getQueue Oct 16 17:44:57 volumio volumio[1429]: info: CorePlayQueue::getQueue Oct 16 17:44:57 volumio volumio[1429]: info: Listing playlists Oct 16 17:44:57 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 16 17:44:57 volumio volumio[1429]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Oct 16 17:44:57 volumio volumio[1429]: info: Received Get System Info Oct 16 17:44:57 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 17:44:57 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 17:44:57 volumio volumio[1429]: info: Discovery: Getting this device information Oct 16 17:44:57 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Oct 16 17:44:57 volumio volumio[1429]: info: CorePlayQueue::getTrack 11 Oct 16 17:44:57 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 17:44:57 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Oct 16 17:44:57 volumio volumio[1429]: info: CorePlayQueue::getTrack 11 Oct 16 17:44:58 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 16 17:44:58 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 17:44:58 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 17:44:58 volumio volumio[1429]: info: Discovery: Getting this device information Oct 16 17:44:58 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Oct 16 17:44:58 volumio volumio[1429]: info: CorePlayQueue::getTrack 11 Oct 16 17:44:58 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 17:44:58 volumio volumio[1429]: verbose: New Socket.io Connection to 192.168.1.136:3000 from 192.168.1.133 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Oct 16 17:44:58 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 16 17:44:58 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 16 17:45:08 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 16 17:45:08 volumio volumio[1429]: info: CURURI: music-library/NAS/nas/Chicago Oct 16 17:45:08 volumio volumio[1429]: info: Preload queue cleared Oct 16 17:45:10 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 16 17:45:10 volumio volumio[1429]: info: CURURI: music-library/NAS/nas/Chicago/FLAC HD Oct 16 17:45:10 volumio volumio[1429]: info: Preload queue cleared Oct 16 17:45:12 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 16 17:45:12 volumio volumio[1429]: info: CURURI: music-library/NAS/nas/Chicago/FLAC HD/1976 - Chicago X Oct 16 17:45:12 volumio volumio[1429]: info: Preload queue cleared Oct 16 17:45:12 volumio volumio[1429]: info: Preloading song: music-library/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/01-Once Or Twice.flac Oct 16 17:45:12 volumio volumio[1429]: info: Preloading song: music-library/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/02-You Are On My Mind.flac Oct 16 17:45:12 volumio volumio[1429]: info: Preloading song: music-library/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/03-Skin Tight.flac Oct 16 17:45:12 volumio volumio[1429]: info: Preloading song: music-library/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/04-If You Leave Me Now.flac Oct 16 17:45:12 volumio volumio[1429]: info: Preloading song: music-library/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/05-Together Again.flac Oct 16 17:45:12 volumio volumio[1429]: info: Preloading song: music-library/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/06-Another Rainy Day In New York City.flac Oct 16 17:45:12 volumio volumio[1429]: info: Preloading song: music-library/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/07-Mama Mama.flac Oct 16 17:45:12 volumio volumio[1429]: info: Preloading song: music-library/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/08-Scrapbook.flac Oct 16 17:45:12 volumio volumio[1429]: info: Preloading song: music-library/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/09-Gently I'll Wake You.flac Oct 16 17:45:12 volumio volumio[1429]: info: Preloading song: music-library/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/10-You Get It Up.flac Oct 16 17:45:12 volumio volumio[1429]: info: Preloading song: music-library/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/11-Hope For Love.flac Oct 16 17:45:12 volumio volumio[1429]: info: Exploding uri music-library/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/01-Once Or Twice.flac in service mpd Oct 16 17:45:12 volumio volumio[1429]: info: ALBUMART /albumart?cacheid=798&web=Chicago/X/extralarge&path=%2Fmnt%2FNAS%2Fnas%2FChicago%2FFLAC%20HD%2F1976%20-%20Chicago%20X%2F01-Once%20Or%20Twice.flac&metadata=false Oct 16 17:45:12 volumio volumio[1429]: info: URI /mnt/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/01-Once Or Twice.flac Oct 16 17:45:12 volumio volumio[1429]: info: Exploding uri music-library/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/02-You Are On My Mind.flac in service mpd Oct 16 17:45:12 volumio volumio[1429]: info: ALBUMART /albumart?cacheid=798&web=Chicago/X/extralarge&path=%2Fmnt%2FNAS%2Fnas%2FChicago%2FFLAC%20HD%2F1976%20-%20Chicago%20X%2F02-You%20Are%20On%20My%20Mind.flac&metadata=false Oct 16 17:45:12 volumio volumio[1429]: info: URI /mnt/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/02-You Are On My Mind.flac Oct 16 17:45:12 volumio volumio[1429]: info: Exploding uri music-library/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/03-Skin Tight.flac in service mpd Oct 16 17:45:12 volumio volumio[1429]: info: ALBUMART /albumart?cacheid=798&web=Chicago/X/extralarge&path=%2Fmnt%2FNAS%2Fnas%2FChicago%2FFLAC%20HD%2F1976%20-%20Chicago%20X%2F03-Skin%20Tight.flac&metadata=false Oct 16 17:45:12 volumio volumio[1429]: info: URI /mnt/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/03-Skin Tight.flac Oct 16 17:45:12 volumio volumio[1429]: info: Exploding uri music-library/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/04-If You Leave Me Now.flac in service mpd Oct 16 17:45:12 volumio volumio[1429]: info: ALBUMART /albumart?cacheid=798&web=Chicago/X/extralarge&path=%2Fmnt%2FNAS%2Fnas%2FChicago%2FFLAC%20HD%2F1976%20-%20Chicago%20X%2F04-If%20You%20Leave%20Me%20Now.flac&metadata=false Oct 16 17:45:12 volumio volumio[1429]: info: URI /mnt/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/04-If You Leave Me Now.flac Oct 16 17:45:12 volumio volumio[1429]: info: Exploding uri music-library/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/05-Together Again.flac in service mpd Oct 16 17:45:12 volumio volumio[1429]: info: ALBUMART /albumart?cacheid=798&web=Chicago/X/extralarge&path=%2Fmnt%2FNAS%2Fnas%2FChicago%2FFLAC%20HD%2F1976%20-%20Chicago%20X%2F05-Together%20Again.flac&metadata=false Oct 16 17:45:12 volumio volumio[1429]: info: URI /mnt/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/05-Together Again.flac Oct 16 17:45:12 volumio volumio[1429]: info: Exploding uri music-library/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/06-Another Rainy Day In New York City.flac in service mpd Oct 16 17:45:12 volumio volumio[1429]: info: ALBUMART /albumart?cacheid=798&web=Chicago/X/extralarge&path=%2Fmnt%2FNAS%2Fnas%2FChicago%2FFLAC%20HD%2F1976%20-%20Chicago%20X%2F06-Another%20Rainy%20Day%20In%20New%20York%20City.flac&metadata=false Oct 16 17:45:12 volumio volumio[1429]: info: URI /mnt/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/06-Another Rainy Day In New York City.flac Oct 16 17:45:12 volumio volumio[1429]: info: Exploding uri music-library/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/07-Mama Mama.flac in service mpd Oct 16 17:45:12 volumio volumio[1429]: info: ALBUMART /albumart?cacheid=798&web=Chicago/X/extralarge&path=%2Fmnt%2FNAS%2Fnas%2FChicago%2FFLAC%20HD%2F1976%20-%20Chicago%20X%2F07-Mama%20Mama.flac&metadata=false Oct 16 17:45:12 volumio volumio[1429]: info: URI /mnt/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/07-Mama Mama.flac Oct 16 17:45:12 volumio volumio[1429]: info: Exploding uri music-library/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/08-Scrapbook.flac in service mpd Oct 16 17:45:12 volumio volumio[1429]: info: ALBUMART /albumart?cacheid=798&web=Chicago/X/extralarge&path=%2Fmnt%2FNAS%2Fnas%2FChicago%2FFLAC%20HD%2F1976%20-%20Chicago%20X%2F08-Scrapbook.flac&metadata=false Oct 16 17:45:12 volumio volumio[1429]: info: URI /mnt/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/08-Scrapbook.flac Oct 16 17:45:12 volumio volumio[1429]: info: Exploding uri music-library/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/09-Gently I'll Wake You.flac in service mpd Oct 16 17:45:12 volumio volumio[1429]: info: ALBUMART /albumart?cacheid=798&web=Chicago/X/extralarge&path=%2Fmnt%2FNAS%2Fnas%2FChicago%2FFLAC%20HD%2F1976%20-%20Chicago%20X%2F09-Gently%20I'll%20Wake%20You.flac&metadata=false Oct 16 17:45:12 volumio volumio[1429]: info: URI /mnt/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/09-Gently I'll Wake You.flac Oct 16 17:45:12 volumio volumio[1429]: info: Exploding uri music-library/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/10-You Get It Up.flac in service mpd Oct 16 17:45:12 volumio volumio[1429]: info: ALBUMART /albumart?cacheid=798&web=Chicago/X/extralarge&path=%2Fmnt%2FNAS%2Fnas%2FChicago%2FFLAC%20HD%2F1976%20-%20Chicago%20X%2F10-You%20Get%20It%20Up.flac&metadata=false Oct 16 17:45:12 volumio volumio[1429]: info: URI /mnt/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/10-You Get It Up.flac Oct 16 17:45:12 volumio volumio[1429]: info: Exploding uri music-library/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/11-Hope For Love.flac in service mpd Oct 16 17:45:12 volumio volumio[1429]: info: ALBUMART /albumart?cacheid=798&web=Chicago/X/extralarge&path=%2Fmnt%2FNAS%2Fnas%2FChicago%2FFLAC%20HD%2F1976%20-%20Chicago%20X%2F11-Hope%20For%20Love.flac&metadata=false Oct 16 17:45:12 volumio volumio[1429]: info: URI /mnt/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/11-Hope For Love.flac Oct 16 17:45:15 volumio volumio[1429]: info: Preload queue cleared Oct 16 17:45:15 volumio volumio[1429]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 16 17:45:15 volumio volumio[1429]: info: CoreStateMachine::ClearQueue Oct 16 17:45:15 volumio volumio[1429]: info: CoreStateMachine::stop Oct 16 17:45:15 volumio volumio[1429]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 17:45:15 volumio volumio[1429]: info: CoreStateMachine::stPlaybackTimer Oct 16 17:45:15 volumio volumio[1429]: info: CoreStateMachine::updateTrackBlock Oct 16 17:45:15 volumio volumio[1429]: info: CorePlayQueue::getTrackBlock Oct 16 17:45:15 volumio volumio[1429]: info: CoreStateMachine::pushState Oct 16 17:45:15 volumio volumio[1429]: info: CorePlayQueue::getTrack 11 Oct 16 17:45:15 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 17:45:15 volumio volumio[1429]: info: CoreCommandRouter::volumioPushState Oct 16 17:45:15 volumio volumio[1429]: info: MRS: Pushing multiroomSync output update for this device Oct 16 17:45:15 volumio volumio[1429]: info: MRS: Pushing multiroomSync output Oct 16 17:45:15 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Oct 16 17:45:15 volumio volumio[1429]: info: CorePlayQueue::getTrack 11 Oct 16 17:45:15 volumio volumio[1429]: info: CoreStateMachine::serviceStop Oct 16 17:45:15 volumio volumio[1429]: info: CorePlayQueue::getTrack 11 Oct 16 17:45:15 volumio volumio[1429]: info: CoreCommandRouter::serviceStop Oct 16 17:45:15 volumio volumio[1429]: info: ControllerMpd::stop Oct 16 17:45:15 volumio volumio[1429]: verbose: ControllerMpd::sendMpdCommand stop Oct 16 17:45:15 volumio volumio[1429]: info: CorePlayQueue::clearPlayQueue Oct 16 17:45:15 volumio volumio[1429]: info: CorePlayQueue::saveQueue Oct 16 17:45:15 volumio volumio[1429]: info: CoreCommandRouter::volumioPushQueue Oct 16 17:45:15 volumio volumio[1429]: info: CoreStateMachine::addQueueItems Oct 16 17:45:15 volumio volumio[1429]: info: CorePlayQueue::addQueueItems Oct 16 17:45:15 volumio volumio[1429]: info: Preload queue cleared Oct 16 17:45:15 volumio volumio[1429]: info: Adding Item to queue: music-library/NAS/nas/Chicago/FLAC HD/1976 - Chicago X Oct 16 17:45:15 volumio volumio[1429]: info: Exploding uri music-library/NAS/nas/Chicago/FLAC HD/1976 - Chicago X in service mpd Oct 16 17:45:15 volumio volumio5-onboarding[1669]: time=2026-10-16T17:45:15.931+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.133:43492,00:00:00:00:00:00%01 @ 0x14012c0" state=STATUS_STOPPED positionMs=0 volume=1 Oct 16 17:45:15 volumio volumio5-onboarding[1669]: time=2026-10-16T17:45:15.931+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.133:43492,00:00:00:00:00:00%01 @ 0x14012c0" id="mnt/NAS/nas/Moriarty/Gee whiz but this is a lonesome town/12 - Gee whiz but this is a lonesome town - Jaywalker (Song for Beryl).flac" title="Jaywalker (Song for Beryl)" Oct 16 17:45:15 volumio volumio[1429]: info: Oct 16 17:45:15 volumio volumio[1429]: ---------------------------- MPD announces state update: player Oct 16 17:45:15 volumio volumio[1429]: info: ALBUMART /albumart?cacheid=798&web=Chicago/X/extralarge&path=%2Fmnt%2FNAS%2Fnas%2FChicago%2FFLAC%20HD%2F1976%20-%20Chicago%20X%2F01-Once%20Or%20Twice.flac&metadata=false Oct 16 17:45:15 volumio volumio[1429]: info: URI /mnt/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/01-Once Or Twice.flac Oct 16 17:45:15 volumio volumio[1429]: info: ALBUMART /albumart?cacheid=798&web=Chicago/X/extralarge&path=%2Fmnt%2FNAS%2Fnas%2FChicago%2FFLAC%20HD%2F1976%20-%20Chicago%20X%2F02-You%20Are%20On%20My%20Mind.flac&metadata=false Oct 16 17:45:15 volumio volumio[1429]: info: URI /mnt/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/02-You Are On My Mind.flac Oct 16 17:45:15 volumio volumio[1429]: info: ALBUMART /albumart?cacheid=798&web=Chicago/X/extralarge&path=%2Fmnt%2FNAS%2Fnas%2FChicago%2FFLAC%20HD%2F1976%20-%20Chicago%20X%2F03-Skin%20Tight.flac&metadata=false Oct 16 17:45:15 volumio volumio[1429]: info: URI /mnt/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/03-Skin Tight.flac Oct 16 17:45:15 volumio volumio[1429]: info: ALBUMART /albumart?cacheid=798&web=Chicago/X/extralarge&path=%2Fmnt%2FNAS%2Fnas%2FChicago%2FFLAC%20HD%2F1976%20-%20Chicago%20X%2F04-If%20You%20Leave%20Me%20Now.flac&metadata=false Oct 16 17:45:15 volumio volumio[1429]: info: URI /mnt/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/04-If You Leave Me Now.flac Oct 16 17:45:15 volumio volumio[1429]: info: ALBUMART /albumart?cacheid=798&web=Chicago/X/extralarge&path=%2Fmnt%2FNAS%2Fnas%2FChicago%2FFLAC%20HD%2F1976%20-%20Chicago%20X%2F05-Together%20Again.flac&metadata=false Oct 16 17:45:15 volumio volumio[1429]: info: URI /mnt/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/05-Together Again.flac Oct 16 17:45:15 volumio volumio[1429]: info: ALBUMART /albumart?cacheid=798&web=Chicago/X/extralarge&path=%2Fmnt%2FNAS%2Fnas%2FChicago%2FFLAC%20HD%2F1976%20-%20Chicago%20X%2F06-Another%20Rainy%20Day%20In%20New%20York%20City.flac&metadata=false Oct 16 17:45:15 volumio volumio[1429]: info: URI /mnt/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/06-Another Rainy Day In New York City.flac Oct 16 17:45:15 volumio volumio[1429]: info: ALBUMART /albumart?cacheid=798&web=Chicago/X/extralarge&path=%2Fmnt%2FNAS%2Fnas%2FChicago%2FFLAC%20HD%2F1976%20-%20Chicago%20X%2F07-Mama%20Mama.flac&metadata=false Oct 16 17:45:15 volumio volumio[1429]: info: URI /mnt/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/07-Mama Mama.flac Oct 16 17:45:15 volumio volumio[1429]: info: ALBUMART /albumart?cacheid=798&web=Chicago/X/extralarge&path=%2Fmnt%2FNAS%2Fnas%2FChicago%2FFLAC%20HD%2F1976%20-%20Chicago%20X%2F08-Scrapbook.flac&metadata=false Oct 16 17:45:15 volumio volumio[1429]: info: URI /mnt/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/08-Scrapbook.flac Oct 16 17:45:15 volumio volumio[1429]: info: ALBUMART /albumart?cacheid=798&web=Chicago/X/extralarge&path=%2Fmnt%2FNAS%2Fnas%2FChicago%2FFLAC%20HD%2F1976%20-%20Chicago%20X%2F09-Gently%20I'll%20Wake%20You.flac&metadata=false Oct 16 17:45:15 volumio volumio[1429]: info: URI /mnt/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/09-Gently I'll Wake You.flac Oct 16 17:45:15 volumio volumio[1429]: info: ALBUMART /albumart?cacheid=798&web=Chicago/X/extralarge&path=%2Fmnt%2FNAS%2Fnas%2FChicago%2FFLAC%20HD%2F1976%20-%20Chicago%20X%2F10-You%20Get%20It%20Up.flac&metadata=false Oct 16 17:45:15 volumio volumio[1429]: info: URI /mnt/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/10-You Get It Up.flac Oct 16 17:45:15 volumio volumio[1429]: info: ALBUMART /albumart?cacheid=798&web=Chicago/X/extralarge&path=%2Fmnt%2FNAS%2Fnas%2FChicago%2FFLAC%20HD%2F1976%20-%20Chicago%20X%2F11-Hope%20For%20Love.flac&metadata=false Oct 16 17:45:15 volumio volumio[1429]: info: URI /mnt/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/11-Hope For Love.flac Oct 16 17:45:15 volumio volumio[1429]: info: sendMpdCommand stop took 45 milliseconds Oct 16 17:45:15 volumio volumio[1429]: info: ControllerMpd::getState Oct 16 17:45:15 volumio volumio[1429]: verbose: ControllerMpd::sendMpdCommand status Oct 16 17:45:15 volumio volumio[1429]: info: CoreCommandRouter::volumioPushQueue Oct 16 17:45:15 volumio volumio[1429]: info: CorePlayQueue::saveQueue Oct 16 17:45:15 volumio volumio[1429]: info: CoreStateMachine::updateTrackBlock Oct 16 17:45:15 volumio volumio[1429]: info: CorePlayQueue::getTrackBlock Oct 16 17:45:15 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Oct 16 17:45:15 volumio volumio[1429]: info: CorePlayQueue::getTrack 11 Oct 16 17:45:15 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Oct 16 17:45:15 volumio volumio[1429]: info: CoreCommandRouter::volumioPlay Oct 16 17:45:15 volumio volumio[1429]: info: CoreStateMachine::play index 0 Oct 16 17:45:15 volumio volumio[1429]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 17:45:15 volumio volumio[1429]: info: CoreStateMachine::stop Oct 16 17:45:15 volumio volumio[1429]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 17:45:15 volumio volumio[1429]: info: CoreStateMachine::play index undefined Oct 16 17:45:15 volumio volumio[1429]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 17:45:15 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Oct 16 17:45:15 volumio volumio[1429]: info: CoreStateMachine::startPlaybackTimer Oct 16 17:45:15 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Oct 16 17:45:15 volumio volumio[1429]: verbose: ControllerMpd::clearAddPlayTracks NAS/nas/Chicago/FLAC HD/1976 - Chicago X/01-Once Or Twice.flac Oct 16 17:45:15 volumio volumio[1429]: verbose: ControllerMpd::sendMpdCommand stop Oct 16 17:45:15 volumio volumio[1429]: info: sendMpdCommand status took 8 milliseconds Oct 16 17:45:15 volumio volumio[1429]: info: sendMpdCommand stop took 3 milliseconds Oct 16 17:45:15 volumio volumio[1429]: verbose: ControllerMpd::parseState Oct 16 17:45:15 volumio volumio[1429]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 17:45:15 volumio volumio[1429]: verbose: ControllerMpd::sendMpdCommand clear Oct 16 17:45:15 volumio volumio[1429]: info: Oct 16 17:45:15 volumio volumio[1429]: ---------------------------- MPD announces system playlist update Oct 16 17:45:15 volumio volumio[1429]: info: Ignoring MPD Status Update Oct 16 17:45:15 volumio volumio[1429]: info: sendMpdCommand playlistinfo took 7 milliseconds Oct 16 17:45:15 volumio volumio[1429]: info: sendMpdCommand clear took 7 milliseconds Oct 16 17:45:15 volumio volumio[1429]: verbose: ControllerMpd::parseTrackInfo Oct 16 17:45:15 volumio volumio[1429]: verbose: ControllerMpd::sendMpdCommand add "NAS/nas/Chicago/FLAC HD/1976 - Chicago X/01-Once Or Twice.flac" Oct 16 17:45:15 volumio volumio[1429]: info: ControllerMpd::pushState Oct 16 17:45:15 volumio volumio[1429]: info: CoreCommandRouter::servicePushState Oct 16 17:45:15 volumio volumio[1429]: info: CoreStateMachine::pushState Oct 16 17:45:15 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Oct 16 17:45:15 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 17:45:15 volumio volumio[1429]: info: CoreCommandRouter::volumioPushState Oct 16 17:45:15 volumio volumio[1429]: info: MRS: Pushing multiroomSync output update for this device Oct 16 17:45:15 volumio volumio[1429]: info: MRS: Pushing multiroomSync output Oct 16 17:45:15 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Oct 16 17:45:15 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Oct 16 17:45:15 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Oct 16 17:45:15 volumio volumio[1429]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Jaywalker (Song for Beryl)","artist":"Moriarty","album":"Gee whiz but this is a lonesome town","uri":"NAS/nas/Moriarty/Gee whiz but this is a lonesome town/12 - Gee whiz but this is a lonesome town - Jaywalker (Song for Beryl).flac","trackType":"flac"} Oct 16 17:45:15 volumio volumio[1429]: verbose: CURRENT POSITION 0 Oct 16 17:45:15 volumio volumio[1429]: info: CoreStateMachine::syncState stateService stop Oct 16 17:45:15 volumio volumio[1429]: info: CoreStateMachine::syncState currentStatus stop Oct 16 17:45:15 volumio volumio[1429]: info: CoreStateMachine::pushState Oct 16 17:45:15 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Oct 16 17:45:15 volumio volumio[1429]: info: CoreCommandRouter::volumioPushState Oct 16 17:45:15 volumio volumio[1429]: info: MRS: Pushing multiroomSync output update for this device Oct 16 17:45:15 volumio volumio[1429]: info: MRS: Pushing multiroomSync output Oct 16 17:45:15 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Oct 16 17:45:15 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Oct 16 17:45:15 volumio volumio[1429]: info: No code Oct 16 17:45:15 volumio volumio[1429]: info: CoreStateMachine::pushState Oct 16 17:45:15 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Oct 16 17:45:15 volumio volumio[1429]: info: CoreCommandRouter::volumioPushState Oct 16 17:45:15 volumio volumio[1429]: info: MRS: Pushing multiroomSync output update for this device Oct 16 17:45:15 volumio volumio[1429]: info: MRS: Pushing multiroomSync output Oct 16 17:45:15 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Oct 16 17:45:15 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Oct 16 17:45:15 volumio volumio5-onboarding[1669]: time=2026-10-16T17:45:15.983+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.133:43492,00:00:00:00:00:00%01 @ 0x14012c0" state=STATUS_STOPPED positionMs=0 volume=1 Oct 16 17:45:15 volumio volumio5-onboarding[1669]: time=2026-10-16T17:45:15.983+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.133:43492,00:00:00:00:00:00%01 @ 0x14012c0" id="mnt/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/01-Once Or Twice.flac" title="Once Or Twice" Oct 16 17:45:15 volumio volumio5-onboarding[1669]: time=2026-10-16T17:45:15.983+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.133:43492,00:00:00:00:00:00%01 @ 0x14012c0" state=STATUS_STOPPED positionMs=0 volume=1 Oct 16 17:45:15 volumio volumio5-onboarding[1669]: time=2026-10-16T17:45:15.983+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.133:43492,00:00:00:00:00:00%01 @ 0x14012c0" id="mnt/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/01-Once Or Twice.flac" title="Once Or Twice" Oct 16 17:45:15 volumio volumio5-onboarding[1669]: time=2026-10-16T17:45:15.985+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.133:43492,00:00:00:00:00:00%01 @ 0x14012c0" state=STATUS_STOPPED positionMs=0 volume=1 Oct 16 17:45:15 volumio volumio5-onboarding[1669]: time=2026-10-16T17:45:15.985+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.133:43492,00:00:00:00:00:00%01 @ 0x14012c0" id="mnt/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/01-Once Or Twice.flac" title="Once Or Twice" Oct 16 17:45:15 volumio volumio[1429]: info: ------------------------------ 47ms Oct 16 17:45:15 volumio volumio[1429]: error: updateQueue error: null Oct 16 17:45:15 volumio volumio[1429]: info: Oct 16 17:45:15 volumio volumio[1429]: ---------------------------- MPD announces system playlist update Oct 16 17:45:15 volumio volumio[1429]: info: Ignoring MPD Status Update Oct 16 17:45:15 volumio volumio[1429]: info: ------------------------------ 29ms Oct 16 17:45:15 volumio volumio[1429]: info: sendMpdCommand add "NAS/nas/Chicago/FLAC HD/1976 - Chicago X/01-Once Or Twice.flac" took 28 milliseconds Oct 16 17:45:15 volumio volumio[1429]: verbose: ControllerMpd::sendMpdCommand play Oct 16 17:45:16 volumio volumio[1429]: info: touch_display: Setting screensaver timeout to 120 seconds. Oct 16 17:45:16 volumio volumio[1429]: info: ------------------------------ 9ms Oct 16 17:45:16 volumio volumio[1429]: info: sendMpdCommand play took 9 milliseconds Oct 16 17:45:17 volumio volumio[1429]: info: Oct 16 17:45:17 volumio volumio[1429]: ---------------------------- MPD announces state update: player Oct 16 17:45:17 volumio volumio[1429]: info: ControllerMpd::getState Oct 16 17:45:17 volumio volumio[1429]: verbose: ControllerMpd::sendMpdCommand status Oct 16 17:45:17 volumio volumio[1429]: info: Oct 16 17:45:17 volumio volumio[1429]: ---------------------------- MPD announces state update: player Oct 16 17:45:17 volumio volumio[1429]: info: ControllerMpd::getState Oct 16 17:45:17 volumio volumio[1429]: verbose: ControllerMpd::sendMpdCommand status Oct 16 17:45:17 volumio volumio[1429]: info: sendMpdCommand status took 3 milliseconds Oct 16 17:45:17 volumio volumio[1429]: verbose: ControllerMpd::parseState Oct 16 17:45:17 volumio volumio[1429]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 17:45:17 volumio volumio[1429]: info: sendMpdCommand status took 2 milliseconds Oct 16 17:45:17 volumio volumio[1429]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 16 17:45:17 volumio volumio[1429]: verbose: ControllerMpd::parseState Oct 16 17:45:17 volumio volumio[1429]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 16 17:45:17 volumio volumio[1429]: verbose: ControllerMpd::parseTrackInfo Oct 16 17:45:17 volumio volumio[1429]: info: ControllerMpd::pushState Oct 16 17:45:17 volumio volumio[1429]: info: CoreCommandRouter::servicePushState Oct 16 17:45:17 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Oct 16 17:45:17 volumio volumio[1429]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1788,"duration":180,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"4885 Kbps","isStreaming":false,"title":"Once Or Twice","artist":"Chicago","album":"X","uri":"NAS/nas/Chicago/FLAC HD/1976 - Chicago X/01-Once Or Twice.flac","trackType":"flac"} Oct 16 17:45:17 volumio volumio[1429]: verbose: CURRENT POSITION 0 Oct 16 17:45:17 volumio volumio[1429]: info: CoreStateMachine::syncState stateService play Oct 16 17:45:17 volumio volumio[1429]: info: CoreStateMachine::syncState currentStatus stop Oct 16 17:45:17 volumio volumio[1429]: info: ------------------------------ 4ms Oct 16 17:45:17 volumio volumio[1429]: info: sendMpdCommand playlistinfo took 23 milliseconds Oct 16 17:45:17 volumio volumio[1429]: verbose: ControllerMpd::parseTrackInfo Oct 16 17:45:17 volumio volumio[1429]: info: ControllerMpd::pushState Oct 16 17:45:17 volumio volumio[1429]: info: CoreCommandRouter::servicePushState Oct 16 17:45:17 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Oct 16 17:45:17 volumio volumio[1429]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1788,"duration":180,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"4885 Kbps","isStreaming":false,"title":"Once Or Twice","artist":"Chicago","album":"X","uri":"NAS/nas/Chicago/FLAC HD/1976 - Chicago X/01-Once Or Twice.flac","trackType":"flac"} Oct 16 17:45:17 volumio volumio[1429]: verbose: CURRENT POSITION 0 Oct 16 17:45:17 volumio volumio[1429]: info: CoreStateMachine::syncState stateService play Oct 16 17:45:17 volumio volumio[1429]: info: CoreStateMachine::syncState currentStatus play Oct 16 17:45:17 volumio volumio[1429]: info: Received an update from plugin. extracting info from payload Oct 16 17:45:17 volumio volumio[1429]: info: CoreStateMachine::pushState Oct 16 17:45:17 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Oct 16 17:45:17 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 17:45:17 volumio volumio[1429]: info: CoreCommandRouter::volumioPushState Oct 16 17:45:17 volumio volumio[1429]: info: MRS: Pushing multiroomSync output update for this device Oct 16 17:45:17 volumio volumio[1429]: info: MRS: Pushing multiroomSync output Oct 16 17:45:17 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Oct 16 17:45:17 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Oct 16 17:45:17 volumio volumio[1429]: info: CoreStateMachine::pushState Oct 16 17:45:17 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Oct 16 17:45:17 volumio volumio[1429]: info: CoreCommandRouter::volumioPushState Oct 16 17:45:17 volumio volumio[1429]: info: MRS: Pushing multiroomSync output update for this device Oct 16 17:45:17 volumio volumio[1429]: info: MRS: Pushing multiroomSync output Oct 16 17:45:17 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Oct 16 17:45:17 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Oct 16 17:45:17 volumio volumio5-onboarding[1669]: time=2026-10-16T17:45:17.351+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.133:43492,00:00:00:00:00:00%01 @ 0x14012c0" state=STATUS_PLAYING positionMs=1788 volume=1 Oct 16 17:45:17 volumio volumio5-onboarding[1669]: time=2026-10-16T17:45:17.351+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.133:43492,00:00:00:00:00:00%01 @ 0x14012c0" id="mnt/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/01-Once Or Twice.flac" title="Once Or Twice" Oct 16 17:45:17 volumio volumio5-onboarding[1669]: time=2026-10-16T17:45:17.352+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.133:43492,00:00:00:00:00:00%01 @ 0x14012c0" state=STATUS_PLAYING positionMs=1788 volume=1 Oct 16 17:45:17 volumio volumio5-onboarding[1669]: time=2026-10-16T17:45:17.352+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.133:43492,00:00:00:00:00:00%01 @ 0x14012c0" id="mnt/NAS/nas/Chicago/FLAC HD/1976 - Chicago X/01-Once Or Twice.flac" title="Once Or Twice" Oct 16 17:45:17 volumio volumio[1429]: info: ------------------------------ 45ms Oct 16 17:45:19 volumio volumio[1429]: verbose: New Socket.io Connection to 192.168.1.136 from 192.168.1.133 UA: Mozilla/5.0 (Linux; Android 17; Pixel 7a Build/CP3A.261005.002.A1; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/153.0.8010.36 Mobile Safari/537.36 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 8 Oct 16 17:45:19 volumio sudo[8010]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 16 17:45:19 volumio sudo[8010]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:45:19 volumio sudo[8010]: pam_unix(sudo:session): session closed for user root Oct 16 17:45:19 volumio sudo[8012]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 16 17:45:19 volumio sudo[8012]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:45:19 volumio sudo[8012]: pam_unix(sudo:session): session closed for user root Oct 16 17:45:19 volumio volumio[1429]: verbose: New Socket.io Connection to 192.168.1.136 from 192.168.1.133 UA: Mozilla/5.0 (Linux; Android 17; Pixel 7a Build/CP3A.261005.002.A1; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/153.0.8010.36 Mobile Safari/537.36 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 9 Oct 16 17:45:19 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 16 17:45:19 volumio volumio[1429]: info: CoreCommandRouter::volumioGetVisibleSources Oct 16 17:45:19 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 17:45:19 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Oct 16 17:45:19 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Oct 16 17:45:19 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 16 17:45:19 volumio volumio[1429]: info: CoreCommandRouter::volumioGetQueue Oct 16 17:45:19 volumio volumio[1429]: info: CoreStateMachine::getQueue Oct 16 17:45:19 volumio volumio[1429]: info: CorePlayQueue::getQueue Oct 16 17:45:19 volumio volumio[1429]: info: Listing playlists Oct 16 17:45:19 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 16 17:45:19 volumio volumio[1429]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Oct 16 17:45:19 volumio volumio[1429]: info: Received Get System Info Oct 16 17:45:19 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 17:45:19 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 17:45:19 volumio volumio[1429]: info: Discovery: Getting this device information Oct 16 17:45:19 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Oct 16 17:45:19 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Oct 16 17:45:19 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 17:45:19 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Oct 16 17:45:19 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Oct 16 17:45:19 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 16 17:45:19 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 16 17:45:19 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 16 17:45:21 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 16 17:45:21 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 17:45:21 volumio volumio[1429]: info: Received Get System Info Oct 16 17:45:21 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 17:45:21 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 17:45:21 volumio volumio[1429]: info: Discovery: Getting this device information Oct 16 17:45:21 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Oct 16 17:45:21 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Oct 16 17:45:21 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 17:45:21 volumio volumio[1429]: verbose: New Socket.io Connection to 192.168.1.136 from 192.168.1.133 UA: Mozilla/5.0 (Linux; Android 17; Pixel 7a Build/CP3A.261005.002.A1; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/153.0.8010.36 Mobile Safari/537.36 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 9 Oct 16 17:45:21 volumio sudo[8017]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 16 17:45:21 volumio sudo[8017]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:45:21 volumio sudo[8017]: pam_unix(sudo:session): session closed for user root Oct 16 17:45:21 volumio sudo[8019]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 16 17:45:21 volumio sudo[8019]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:45:21 volumio sudo[8019]: pam_unix(sudo:session): session closed for user root Oct 16 17:45:22 volumio volumio[1429]: verbose: New Socket.io Connection to 192.168.1.136 from 192.168.1.133 UA: Mozilla/5.0 (Linux; Android 17; Pixel 7a Build/CP3A.261005.002.A1; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/153.0.8010.36 Mobile Safari/537.36 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 10 Oct 16 17:45:22 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 16 17:45:22 volumio volumio[1429]: info: CoreCommandRouter::volumioGetVisibleSources Oct 16 17:45:22 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 17:45:22 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Oct 16 17:45:22 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Oct 16 17:45:22 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 16 17:45:22 volumio volumio[1429]: info: CoreCommandRouter::volumioGetQueue Oct 16 17:45:22 volumio volumio[1429]: info: CoreStateMachine::getQueue Oct 16 17:45:22 volumio volumio[1429]: info: CorePlayQueue::getQueue Oct 16 17:45:22 volumio volumio[1429]: info: Listing playlists Oct 16 17:45:22 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 16 17:45:22 volumio volumio[1429]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Oct 16 17:45:22 volumio volumio[1429]: info: Received Get System Info Oct 16 17:45:22 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 17:45:22 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 17:45:22 volumio volumio[1429]: info: Discovery: Getting this device information Oct 16 17:45:22 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Oct 16 17:45:22 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Oct 16 17:45:22 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 17:45:22 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Oct 16 17:45:22 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Oct 16 17:45:22 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 16 17:45:22 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 16 17:45:22 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 16 17:45:23 volumio volumio[1429]: verbose: New Socket.io Connection to 192.168.1.136 from 192.168.1.133 UA: Mozilla/5.0 (Linux; Android 17; Pixel 7a Build/CP3A.261005.002.A1; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/153.0.8010.36 Mobile Safari/537.36 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 10 Oct 16 17:45:23 volumio sudo[8023]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 16 17:45:23 volumio sudo[8023]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:45:23 volumio sudo[8023]: pam_unix(sudo:session): session closed for user root Oct 16 17:45:23 volumio sudo[8025]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 16 17:45:23 volumio sudo[8025]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 16 17:45:23 volumio sudo[8025]: pam_unix(sudo:session): session closed for user root Oct 16 17:45:23 volumio volumio[1429]: verbose: New Socket.io Connection to 192.168.1.136 from 192.168.1.133 UA: Mozilla/5.0 (Linux; Android 17; Pixel 7a Build/CP3A.261005.002.A1; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/153.0.8010.36 Mobile Safari/537.36 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 11 Oct 16 17:45:23 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 16 17:45:23 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 16 17:45:23 volumio volumio[1429]: info: CoreCommandRouter::volumioGetVisibleSources Oct 16 17:45:23 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 17:45:23 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Oct 16 17:45:23 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Oct 16 17:45:23 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 16 17:45:23 volumio volumio[1429]: info: CoreCommandRouter::volumioGetQueue Oct 16 17:45:23 volumio volumio[1429]: info: CoreStateMachine::getQueue Oct 16 17:45:23 volumio volumio[1429]: info: CorePlayQueue::getQueue Oct 16 17:45:23 volumio volumio[1429]: info: Listing playlists Oct 16 17:45:23 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 16 17:45:23 volumio volumio[1429]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Oct 16 17:45:23 volumio volumio[1429]: info: Received Get System Info Oct 16 17:45:23 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 17:45:23 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 17:45:23 volumio volumio[1429]: info: Discovery: Getting this device information Oct 16 17:45:23 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Oct 16 17:45:23 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Oct 16 17:45:23 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 17:45:23 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Oct 16 17:45:23 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Oct 16 17:45:23 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 16 17:45:23 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 16 17:45:25 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 16 17:45:25 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 17:45:25 volumio volumio[1429]: info: Received Get System Info Oct 16 17:45:25 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 17:45:25 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 17:45:25 volumio volumio[1429]: info: Discovery: Getting this device information Oct 16 17:45:25 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Oct 16 17:45:25 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Oct 16 17:45:25 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 17:45:26 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 17:45:26 volumio volumio[1429]: info: Received Get System Info Oct 16 17:45:26 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 17:45:26 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 17:45:26 volumio volumio[1429]: info: Discovery: Getting this device information Oct 16 17:45:26 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Oct 16 17:45:26 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Oct 16 17:45:26 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 17:45:33 volumio volumio[1429]: Searching plugin music_service/mpd Oct 16 17:45:33 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: mpd , search Oct 16 17:45:33 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 16 17:45:33 volumio volumio[1429]: info: All search sources collected, pushing search results Oct 16 17:45:43 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 16 17:45:44 volumio volumio[1429]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Oct 16 17:45:44 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Oct 16 17:45:44 volumio volumio[1429]: info: Received Get System Version Oct 16 17:45:44 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 17:45:44 volumio volumio[1429]: info: Received Get System Info Oct 16 17:45:44 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 17:45:44 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 17:45:44 volumio volumio[1429]: info: Discovery: Getting this device information Oct 16 17:45:44 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Oct 16 17:45:44 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Oct 16 17:45:44 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 17:45:52 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 16 17:45:52 volumio volumio[1429]: info: CURURI: artists:// Oct 16 17:45:52 volumio volumio[1429]: info: Preload queue cleared Oct 16 17:45:58 volumio volumio[1429]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 17:45:58 volumio volumio[1429]: TypeError: Cannot read properties of null (reading 'slice') Oct 16 17:45:58 volumio volumio[1429]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41) Oct 16 17:45:58 volumio volumio[1429]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7) Oct 16 17:45:58 volumio volumio[1429]: at Object.onceWrapper (node:events:629:26) Oct 16 17:45:58 volumio volumio[1429]: at ClientRequest.emit (node:events:514:28) Oct 16 17:45:58 volumio volumio[1429]: at HTTPParser.parserOnIncomingClient [as onIncoming] (node:_http_client:693:27) Oct 16 17:45:58 volumio volumio[1429]: at HTTPParser.parserOnHeadersComplete (node:_http_common:119:17) Oct 16 17:45:58 volumio volumio[1429]: at TLSSocket.socketOnData (node:_http_client:535:22) Oct 16 17:45:58 volumio volumio[1429]: at TLSSocket.emit (node:events:514:28) Oct 16 17:45:58 volumio volumio[1429]: at addChunk (node:internal/streams/readable:343:12) Oct 16 17:45:58 volumio volumio[1429]: at readableAddChunk (node:internal/streams/readable:316:9) Oct 16 17:45:58 volumio volumio[1429]: at Readable.push (node:internal/streams/readable:253:10) Oct 16 17:45:58 volumio volumio[1429]: at TLSWrap.onStreamRead (node:internal/stream_base_commons:190:23) Oct 16 17:45:58 volumio volumio[1429]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 17:45:58 volumio sudo[8101]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-16 17:44' Oct 16 17:45:58 volumio sudo[8101]: 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"