Oct 02 20:30:06 volumio volumio[1271]: info: CoreCommandRouter::volumioGetState Oct 02 20:30:06 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 02 20:30:07 volumio launch-soloist.sh[17305]: 2026-10-02 20:30:07.813: playing spotify:track:3qrlMjKT7Rj0i4fHFBHHzI "Not Yet" by "ZOYA" [0:10 / 3:11] Oct 02 20:30:17 volumio launch-soloist.sh[17305]: 2026-10-02 20:30:17.812: playing spotify:track:3qrlMjKT7Rj0i4fHFBHHzI "Not Yet" by "ZOYA" [0:20 / 3:11] Oct 02 20:30:26 volumio volumio5-onboarding[1599]: time=2026-10-02T20:30:26.985+03:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.17:39804 @ 0x33f6240" latency=395.155271ms timeout=10s Oct 02 20:30:27 volumio volumio5-onboarding[1599]: time=2026-10-02T20:30:27.097+03:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.17:39804 @ 0x33f6240" latency=395.155271ms timeout=10s endpoint=http://pushupdates.volumio.org duration=110.519855ms Oct 02 20:30:27 volumio volumio5-onboarding[1599]: time=2026-10-02T20:30:27.219+03:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.17:39804 @ 0x33f6240" latency=395.155271ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=233.829868ms Oct 02 20:30:27 volumio volumio5-onboarding[1599]: time=2026-10-02T20:30:27.269+03:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.17:39804 @ 0x33f6240" latency=395.155271ms timeout=10s endpoint=https://www.googleapis.com duration=282.158753ms Oct 02 20:30:27 volumio volumio5-onboarding[1599]: time=2026-10-02T20:30:27.293+03:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.17:39804 @ 0x33f6240" latency=395.155271ms timeout=10s endpoint=https://securetoken.googleapis.com duration=306.724437ms Oct 02 20:30:27 volumio volumio5-onboarding[1599]: time=2026-10-02T20:30:27.390+03:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.17:39804 @ 0x33f6240" latency=395.155271ms timeout=10s endpoint=https://functions.volumio.cloud duration=405.191469ms Oct 02 20:30:27 volumio volumio5-onboarding[1599]: time=2026-10-02T20:30:27.392+03:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.17:39804 @ 0x33f6240" latency=395.155271ms timeout=10s endpoint=https://functions.volumio.cloud duration=404.47895ms Oct 02 20:30:27 volumio volumio5-onboarding[1599]: time=2026-10-02T20:30:27.465+03:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.17:39804 @ 0x33f6240" latency=395.155271ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=479.18778ms Oct 02 20:30:27 volumio volumio5-onboarding[1599]: time=2026-10-02T20:30:27.502+03:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.17:39804 @ 0x33f6240" latency=395.155271ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=514.672805ms Oct 02 20:30:27 volumio volumio5-onboarding[1599]: time=2026-10-02T20:30:27.512+03:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.17:39804 @ 0x33f6240" latency=395.155271ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=525.436109ms Oct 02 20:30:27 volumio volumio5-onboarding[1599]: time=2026-10-02T20:30:27.515+03:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.17:39804 @ 0x33f6240" latency=395.155271ms timeout=10s endpoint=https://database.volumio.cloud duration=527.992925ms Oct 02 20:30:27 volumio volumio5-onboarding[1599]: time=2026-10-02T20:30:27.567+03:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.17:39804 @ 0x33f6240" latency=395.155271ms timeout=10s endpoint=http://cddb.volumio.org duration=579.903443ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 02 20:30:27 volumio volumio5-onboarding[1599]: time=2026-10-02T20:30:27.730+03:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.17:39804 @ 0x33f6240" latency=395.155271ms timeout=10s endpoint=http://plugins.volumio.org duration=741.685631ms Oct 02 20:30:27 volumio volumio5-onboarding[1599]: time=2026-10-02T20:30:27.740+03:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.0.17:39804 @ 0x33f6240" latency=395.155271ms timeout=10s endpoint=https://google.com duration=752.897602ms Oct 02 20:30:27 volumio launch-soloist.sh[17305]: 2026-10-02 20:30:27.813: playing spotify:track:3qrlMjKT7Rj0i4fHFBHHzI "Not Yet" by "ZOYA" [0:30 / 3:11] Oct 02 20:30:28 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 20:30:28 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 20:30:28 volumio volumio[1271]: info: Discovery: Getting this device information Oct 02 20:30:28 volumio volumio[1271]: info: CoreCommandRouter::volumioGetState Oct 02 20:30:28 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 20:30:28 volumio volumio[1271]: verbose: New Socket.io Connection to 192.168.0.20:3000 from 192.168.0.17 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 11 Oct 02 20:30:28 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 02 20:30:28 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 02 20:30:28 volumio volumio[1271]: verbose: New Socket.io Connection to 192.168.0.20 from 192.168.0.17 UA: Mozilla/5.0 (Linux; Android 16; I2508 Build/BP2A.250605.031.A3_V000L1; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/153.0.8010.36 Mobile Safari/537.36 VolumioApp/6.260915.0 Engine version: 3 Transport: polling Total Clients: 11 Oct 02 20:30:28 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 02 20:30:28 volumio volumio[1271]: info: CoreCommandRouter::volumioGetVisibleSources Oct 02 20:30:28 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 02 20:30:28 volumio volumio[1271]: info: CoreCommandRouter::volumioGetState Oct 02 20:30:28 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 02 20:30:28 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 02 20:30:28 volumio volumio[1271]: info: Received Get System Info Oct 02 20:30:28 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 02 20:30:28 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 02 20:30:28 volumio volumio[1271]: info: Discovery: Getting this device information Oct 02 20:30:28 volumio volumio[1271]: info: CoreCommandRouter::volumioGetState Oct 02 20:30:28 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 02 20:30:28 volumio volumio[1271]: info: CoreCommandRouter::volumioGetState Oct 02 20:30:28 volumio volumio[1271]: info: Listing playlists Oct 02 20:30:28 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 02 20:30:37 volumio volumio[1271]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 02 20:30:37 volumio volumio[1271]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 02 20:30:37 volumio volumio[1271]: info: Retrieving Cloud Streaming UI Oct 02 20:30:37 volumio volumio[1271]: info: Getting Tidal Cloud Configuration Oct 02 20:30:37 volumio volumio[1271]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 02 20:30:37 volumio volumio[1271]: info: Getting Qobuz Cloud Configuration Oct 02 20:30:37 volumio volumio[1271]: info: Asking plugin for UI Config Oct 02 20:30:37 volumio volumio[1271]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 02 20:30:37 volumio volumio[1271]: info: Getting Spotify Cloud Configuration Oct 02 20:30:37 volumio volumio[1271]: info: Asking plugin for UI Config Oct 02 20:30:37 volumio volumio[1271]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 02 20:30:37 volumio volumio[1271]: info: Saving Spotify Acccount Oct 02 20:30:37 volumio volumio[1271]: info: Got Tidal Cloud Configuration Oct 02 20:30:37 volumio volumio[1271]: info: Got it Oct 02 20:30:37 volumio volumio[1271]: info: Got it Oct 02 20:30:37 volumio volumio[1271]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Oct 02 20:30:37 volumio volumio[1271]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 02 20:30:37 volumio volumio[1271]: error: Error retrieving Highresaudio conf: TypeError: Cannot read properties of undefined (reading 'onSave') Oct 02 20:30:37 volumio launch-soloist.sh[17305]: 2026-10-02 20:30:37.813: playing spotify:track:3qrlMjKT7Rj0i4fHFBHHzI "Not Yet" by "ZOYA" [0:40 / 3:11] Oct 02 20:30:37 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 02 20:30:37 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 02 20:30:37 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 02 20:30:37 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 02 20:30:37 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 02 20:30:37 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 02 20:30:37 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 02 20:30:37 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 02 20:30:37 volumio volumio[1271]: info: CoreCommandRouter::volumioGetBrowseSources Oct 02 20:30:37 volumio volumio[1271]: info: CoreCommandRouter::volumioGetBrowseSources Oct 02 20:30:37 volumio volumio[1271]: info: CoreCommandRouter::volumioGetBrowseSources Oct 02 20:30:37 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 02 20:30:37 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Oct 02 20:30:41 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 02 20:30:47 volumio launch-soloist.sh[17305]: 2026-10-02 20:30:47.813: playing spotify:track:3qrlMjKT7Rj0i4fHFBHHzI "Not Yet" by "ZOYA" [0:50 / 3:11] Oct 02 20:30:53 volumio volumio[1271]: info: CoreCommandRouter::volumioGetQueue Oct 02 20:30:53 volumio volumio[1271]: info: CoreStateMachine::getQueue Oct 02 20:30:53 volumio volumio[1271]: info: CorePlayQueue::getQueue Oct 02 20:30:57 volumio launch-soloist.sh[17305]: 2026-10-02 20:30:57.813: playing spotify:track:3qrlMjKT7Rj0i4fHFBHHzI "Not Yet" by "ZOYA" [1:00 / 3:11] Oct 02 20:31:00 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 02 20:31:00 volumio volumio[1271]: info: Preload queue cleared Oct 02 20:31:04 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 02 20:31:04 volumio volumio[1271]: info: Preload queue cleared Oct 02 20:31:07 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Oct 02 20:31:07 volumio launch-soloist.sh[17305]: 2026-10-02 20:31:07.812: playing spotify:track:3qrlMjKT7Rj0i4fHFBHHzI "Not Yet" by "ZOYA" [1:10 / 3:11] Oct 02 20:31:08 volumio volumio[1271]: info: Preload queue cleared Oct 02 20:31:10 volumio volumio[1271]: info: Preload queue cleared Oct 02 20:31:10 volumio volumio[1271]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 02 20:31:10 volumio volumio[1271]: info: CoreStateMachine::ClearQueue Oct 02 20:31:10 volumio volumio[1271]: info: CoreStateMachine::stop Oct 02 20:31:10 volumio volumio[1271]: info: CoreStateMachine::serviceStop Oct 02 20:31:10 volumio volumio[1271]: info: CoreCommandRouter::serviceStop Oct 02 20:31:10 volumio volumio[1271]: info: SoloistConnect: yielding playback Oct 02 20:31:10 volumio launch-soloist.sh[17305]: 2026-10-02 20:31:10.961: paused spotify:track:3qrlMjKT7Rj0i4fHFBHHzI "Not Yet" by "ZOYA" [0:00 / 3:11] Oct 02 20:31:10 volumio volumio[1271]: info: CorePlayQueue::clearPlayQueue Oct 02 20:31:10 volumio volumio[1271]: info: CorePlayQueue::saveQueue Oct 02 20:31:10 volumio volumio[1271]: info: CoreCommandRouter::volumioPushQueue Oct 02 20:31:10 volumio volumio[1271]: info: CoreStateMachine::addQueueItems Oct 02 20:31:10 volumio volumio[1271]: info: CorePlayQueue::addQueueItems Oct 02 20:31:10 volumio volumio[1271]: info: Preload queue cleared Oct 02 20:31:10 volumio volumio[1271]: info: Adding Item to queue: http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99555531 Oct 02 20:31:10 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 02 20:31:11 volumio volumio[1271]: info: CoreCommandRouter::volumioPushQueue Oct 02 20:31:11 volumio volumio[1271]: info: CorePlayQueue::saveQueue Oct 02 20:31:11 volumio volumio[1271]: info: CoreStateMachine::updateTrackBlock Oct 02 20:31:11 volumio volumio[1271]: info: CorePlayQueue::getTrackBlock Oct 02 20:31:11 volumio volumio[1271]: info: CoreCommandRouter::volumioPlay Oct 02 20:31:11 volumio volumio[1271]: verbose: UNSET VOLATILE: Service: soloist_connect Oct 02 20:31:11 volumio volumio[1271]: info: CoreCommandRouter::servicePushState Oct 02 20:31:11 volumio volumio[1271]: info: CoreStateMachine::pushState Oct 02 20:31:11 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 20:31:11 volumio volumio[1271]: info: CoreCommandRouter::volumioPushState Oct 02 20:31:11 volumio volumio[1271]: verbose: UNSET VOLATILE: Service: soloist_connect Oct 02 20:31:11 volumio volumio[1271]: info: CoreStateMachine::play index 0 Oct 02 20:31:11 volumio volumio[1271]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 02 20:31:11 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:11.147+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" state=STATUS_PAUSED positionMs=73111 volume=50 Oct 02 20:31:11 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:11.147+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" id=spotify:track:3qrlMjKT7Rj0i4fHFBHHzI title="Not Yet" Oct 02 20:31:11 volumio volumio[1271]: info: CoreStateMachine::stop Oct 02 20:31:11 volumio volumio[1271]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 02 20:31:11 volumio volumio[1271]: info: CoreStateMachine::updateTrackBlock Oct 02 20:31:11 volumio volumio[1271]: info: CorePlayQueue::getTrackBlock Oct 02 20:31:11 volumio volumio[1271]: info: CoreStateMachine::stPlaybackTimer Oct 02 20:31:11 volumio volumio[1271]: info: CoreStateMachine::pushState Oct 02 20:31:11 volumio volumio[1271]: info: CorePlayQueue::getTrack 0 Oct 02 20:31:11 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 20:31:11 volumio volumio[1271]: info: CoreCommandRouter::volumioPushState Oct 02 20:31:11 volumio volumio[1271]: info: CoreStateMachine::serviceStop Oct 02 20:31:11 volumio volumio[1271]: info: CorePlayQueue::getTrack 0 Oct 02 20:31:11 volumio volumio[1271]: info: CoreCommandRouter::serviceStop Oct 02 20:31:11 volumio volumio[1271]: info: [1790962271152] ControllerWebradio::stop Oct 02 20:31:11 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand stop Oct 02 20:31:11 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:11.155+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" state=STATUS_STOPPED positionMs=0 volume=50 Oct 02 20:31:11 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:11.155+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" id="http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99555531" title="DEEP FM - amgradio.ru" Oct 02 20:31:11 volumio volumio[1271]: info: SoloistConnect: open /data/soloist/cache/cache/5a/5a7f5749386f542ec02c28dcadd8d868982aa926.file 3666303 bytes over 191s = 153 kbps (growing, hold) Oct 02 20:31:11 volumio volumio[1271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Oct 02 20:31:11 volumio volumio[1271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Oct 02 20:31:11 volumio volumio[1271]: info: Oct 02 20:31:11 volumio volumio[1271]: ---------------------------- MPD announces state update: player Oct 02 20:31:11 volumio volumio[1271]: info: sendMpdCommand stop took 112 milliseconds Oct 02 20:31:11 volumio volumio[1271]: info: ControllerMpd::getState Oct 02 20:31:11 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand status Oct 02 20:31:11 volumio volumio[1271]: info: CoreStateMachine::play index undefined Oct 02 20:31:11 volumio volumio[1271]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 02 20:31:11 volumio volumio[1271]: info: CorePlayQueue::getTrack 0 Oct 02 20:31:11 volumio volumio[1271]: info: CoreStateMachine::startPlaybackTimer Oct 02 20:31:11 volumio volumio[1271]: info: CorePlayQueue::getTrack 0 Oct 02 20:31:11 volumio volumio[1271]: info: [1790962271266] ControllerWebradio::clearAddPlayTrack Oct 02 20:31:11 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand stop Oct 02 20:31:11 volumio volumio[1271]: info: SoloistConnect: open /data/soloist/cache/cache/5a/5a7f5749386f542ec02c28dcadd8d868982aa926.file 3666303 bytes over 191s = 153 kbps (growing, hold) Oct 02 20:31:11 volumio volumio[1271]: info: sendMpdCommand status took 43 milliseconds Oct 02 20:31:11 volumio volumio[1271]: info: sendMpdCommand stop took 41 milliseconds Oct 02 20:31:11 volumio volumio[1271]: verbose: ControllerMpd::parseState Oct 02 20:31:11 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 02 20:31:11 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand clear Oct 02 20:31:11 volumio volumio[1271]: info: Oct 02 20:31:11 volumio volumio[1271]: ---------------------------- MPD announces state update: player Oct 02 20:31:11 volumio volumio[1271]: info: ControllerMpd::getState Oct 02 20:31:11 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand status Oct 02 20:31:11 volumio volumio[1271]: info: Oct 02 20:31:11 volumio volumio[1271]: ---------------------------- MPD announces system playlist update Oct 02 20:31:11 volumio volumio[1271]: info: Ignoring MPD Status Update Oct 02 20:31:11 volumio volumio[1271]: info: sendMpdCommand playlistinfo took 23 milliseconds Oct 02 20:31:11 volumio volumio[1271]: info: sendMpdCommand clear took 23 milliseconds Oct 02 20:31:11 volumio volumio[1271]: verbose: ControllerMpd::parseTrackInfo Oct 02 20:31:11 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99555531" Oct 02 20:31:11 volumio volumio[1271]: info: ControllerMpd::pushState Oct 02 20:31:11 volumio volumio[1271]: info: CoreCommandRouter::servicePushState Oct 02 20:31:11 volumio volumio[1271]: info: CoreStateMachine::pushState Oct 02 20:31:11 volumio volumio[1271]: info: CorePlayQueue::getTrack 0 Oct 02 20:31:11 volumio volumio[1271]: info: CoreCommandRouter::volumioPushState Oct 02 20:31:11 volumio volumio[1271]: info: CorePlayQueue::getTrack 0 Oct 02 20:31:11 volumio volumio[1271]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 02 20:31:11 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:11.346+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" state=STATUS_STOPPED positionMs=0 volume=50 Oct 02 20:31:11 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:11.347+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" id="http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99555531" title="DEEP FM - amgradio.ru" Oct 02 20:31:11 volumio volumio[1271]: info: ------------------------------ 85ms Oct 02 20:31:11 volumio volumio[1271]: info: Oct 02 20:31:11 volumio volumio[1271]: ---------------------------- MPD announces system playlist update Oct 02 20:31:11 volumio volumio[1271]: info: Ignoring MPD Status Update Oct 02 20:31:11 volumio volumio[1271]: error: updateQueue error: null Oct 02 20:31:11 volumio volumio[1271]: info: sendMpdCommand status took 28 milliseconds Oct 02 20:31:11 volumio volumio[1271]: info: ------------------------------ 27ms Oct 02 20:31:11 volumio volumio[1271]: verbose: ControllerMpd::parseState Oct 02 20:31:11 volumio volumio[1271]: info: ControllerMpd::pushState Oct 02 20:31:11 volumio volumio[1271]: info: CoreCommandRouter::servicePushState Oct 02 20:31:11 volumio volumio[1271]: info: CoreStateMachine::pushState Oct 02 20:31:11 volumio volumio[1271]: info: CorePlayQueue::getTrack 0 Oct 02 20:31:11 volumio volumio[1271]: info: CoreCommandRouter::volumioPushState Oct 02 20:31:11 volumio volumio[1271]: info: CorePlayQueue::getTrack 0 Oct 02 20:31:11 volumio volumio[1271]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 02 20:31:11 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:11.366+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" state=STATUS_STOPPED positionMs=0 volume=50 Oct 02 20:31:11 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:11.366+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" id="http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99555531" title="DEEP FM - amgradio.ru" Oct 02 20:31:11 volumio volumio[1271]: info: ------------------------------ 42ms Oct 02 20:31:11 volumio volumio[1271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Oct 02 20:31:11 volumio volumio[1271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Oct 02 20:31:11 volumio volumio[1271]: info: touch_display: Setting screensaver timeout to 3600 seconds. Oct 02 20:31:11 volumio volumio[1271]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99555531" took 514 milliseconds Oct 02 20:31:11 volumio volumio[1271]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 02 20:31:11 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand play Oct 02 20:31:11 volumio volumio[1271]: info: Oct 02 20:31:11 volumio volumio[1271]: ---------------------------- MPD announces system playlist update Oct 02 20:31:11 volumio volumio[1271]: info: Ignoring MPD Status Update Oct 02 20:31:11 volumio volumio[1271]: info: ------------------------------ 503ms Oct 02 20:31:11 volumio volumio[1271]: info: Oct 02 20:31:11 volumio volumio[1271]: ---------------------------- MPD announces system playlist update Oct 02 20:31:11 volumio volumio[1271]: info: Ignoring MPD Status Update Oct 02 20:31:11 volumio volumio[1271]: info: sendMpdCommand play took 3 milliseconds Oct 02 20:31:11 volumio volumio[1271]: info: ------------------------------ 3ms Oct 02 20:31:11 volumio volumio[1271]: info: ------------------------------ 1ms Oct 02 20:31:12 volumio volumio[1271]: info: Oct 02 20:31:12 volumio volumio[1271]: ---------------------------- MPD announces state update: player Oct 02 20:31:12 volumio volumio[1271]: info: ControllerMpd::getState Oct 02 20:31:12 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand status Oct 02 20:31:12 volumio volumio[1271]: info: Oct 02 20:31:12 volumio volumio[1271]: ---------------------------- MPD announces state update: player Oct 02 20:31:12 volumio volumio[1271]: info: ControllerMpd::getState Oct 02 20:31:12 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand status Oct 02 20:31:12 volumio volumio[1271]: info: Oct 02 20:31:12 volumio volumio[1271]: ---------------------------- MPD announces state update: player Oct 02 20:31:12 volumio volumio[1271]: info: ControllerMpd::getState Oct 02 20:31:12 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand status Oct 02 20:31:12 volumio volumio[1271]: info: Oct 02 20:31:12 volumio volumio[1271]: ---------------------------- MPD announces state update: player Oct 02 20:31:12 volumio volumio[1271]: info: sendMpdCommand status took 3 milliseconds Oct 02 20:31:12 volumio volumio[1271]: info: ControllerMpd::getState Oct 02 20:31:12 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand status Oct 02 20:31:12 volumio volumio[1271]: info: sendMpdCommand status took 2 milliseconds Oct 02 20:31:12 volumio volumio[1271]: verbose: ControllerMpd::parseState Oct 02 20:31:12 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 02 20:31:12 volumio volumio[1271]: verbose: ControllerMpd::parseState Oct 02 20:31:12 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 02 20:31:12 volumio volumio[1271]: info: sendMpdCommand status took 3 milliseconds Oct 02 20:31:12 volumio volumio[1271]: info: sendMpdCommand status took 2 milliseconds Oct 02 20:31:12 volumio volumio[1271]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 02 20:31:12 volumio volumio[1271]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 02 20:31:12 volumio volumio[1271]: verbose: ControllerMpd::parseState Oct 02 20:31:12 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 02 20:31:12 volumio volumio[1271]: verbose: ControllerMpd::parseState Oct 02 20:31:12 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 02 20:31:12 volumio volumio[1271]: verbose: ControllerMpd::parseTrackInfo Oct 02 20:31:12 volumio volumio[1271]: verbose: ControllerMpd::parseTrackInfo Oct 02 20:31:12 volumio volumio[1271]: info: ControllerMpd::pushState Oct 02 20:31:12 volumio volumio[1271]: info: CoreCommandRouter::servicePushState Oct 02 20:31:12 volumio volumio[1271]: info: CorePlayQueue::getTrack 0 Oct 02 20:31:12 volumio volumio[1271]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"DeepFM","artist":"(#1 - 17600/512) DEEP FM - amgradio.ru","album":null,"uri":"http://shout.amgradio.ru:80/DeepFM","trackType":""} Oct 02 20:31:12 volumio volumio[1271]: verbose: CURRENT POSITION 0 Oct 02 20:31:12 volumio volumio[1271]: info: CoreStateMachine::syncState stateService play Oct 02 20:31:12 volumio volumio[1271]: info: CoreStateMachine::syncState currentStatus stop Oct 02 20:31:12 volumio volumio[1271]: info: ControllerMpd::pushState Oct 02 20:31:12 volumio volumio[1271]: info: CoreCommandRouter::servicePushState Oct 02 20:31:12 volumio volumio[1271]: info: CorePlayQueue::getTrack 0 Oct 02 20:31:12 volumio volumio[1271]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"DeepFM","artist":"(#1 - 17600/512) DEEP FM - amgradio.ru","album":null,"uri":"http://shout.amgradio.ru:80/DeepFM","trackType":""} Oct 02 20:31:12 volumio volumio[1271]: verbose: CURRENT POSITION 0 Oct 02 20:31:12 volumio volumio[1271]: info: CoreStateMachine::syncState stateService play Oct 02 20:31:12 volumio volumio[1271]: info: CoreStateMachine::syncState currentStatus play Oct 02 20:31:12 volumio volumio[1271]: info: Received an update from plugin. extracting info from payload Oct 02 20:31:12 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Oct 02 20:31:12 volumio volumio[1271]: info: CoreStateMachine::pushState Oct 02 20:31:12 volumio volumio[1271]: info: CorePlayQueue::getTrack 0 Oct 02 20:31:12 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 20:31:12 volumio volumio[1271]: info: CoreCommandRouter::volumioPushState Oct 02 20:31:12 volumio volumio[1271]: info: CoreStateMachine::pushState Oct 02 20:31:12 volumio volumio[1271]: info: CoreCommandRouter::volumioPushState Oct 02 20:31:12 volumio volumio[1271]: info: ------------------------------ 15ms Oct 02 20:31:12 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:12.020+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" state=STATUS_PLAYING positionMs=0 volume=50 Oct 02 20:31:12 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:12.021+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" id=http://shout.amgradio.ru:80/DeepFM title="DEEP FM - amgradio.ru" Oct 02 20:31:12 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:12.022+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" state=STATUS_PLAYING positionMs=0 volume=50 Oct 02 20:31:12 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:12.022+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" id=http://shout.amgradio.ru:80/DeepFM title="DEEP FM - amgradio.ru" Oct 02 20:31:12 volumio volumio[1271]: info: ------------------------------ 19ms Oct 02 20:31:12 volumio volumio[1271]: info: sendMpdCommand playlistinfo took 15 milliseconds Oct 02 20:31:12 volumio volumio[1271]: info: sendMpdCommand playlistinfo took 15 milliseconds Oct 02 20:31:12 volumio volumio[1271]: verbose: ControllerMpd::parseTrackInfo Oct 02 20:31:12 volumio volumio[1271]: verbose: ControllerMpd::parseTrackInfo Oct 02 20:31:12 volumio volumio[1271]: info: ControllerMpd::pushState Oct 02 20:31:12 volumio volumio[1271]: info: CoreCommandRouter::servicePushState Oct 02 20:31:12 volumio volumio[1271]: info: CorePlayQueue::getTrack 0 Oct 02 20:31:12 volumio volumio[1271]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"DeepFM","artist":"(#1 - 17600/512) DEEP FM - amgradio.ru","album":null,"uri":"http://shout.amgradio.ru:80/DeepFM","trackType":""} Oct 02 20:31:12 volumio volumio[1271]: verbose: CURRENT POSITION 0 Oct 02 20:31:12 volumio volumio[1271]: info: CoreStateMachine::syncState stateService play Oct 02 20:31:12 volumio volumio[1271]: info: CoreStateMachine::syncState currentStatus play Oct 02 20:31:12 volumio volumio[1271]: info: Received an update from plugin. extracting info from payload Oct 02 20:31:12 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Oct 02 20:31:12 volumio volumio[1271]: info: CoreStateMachine::pushState Oct 02 20:31:12 volumio volumio[1271]: info: CorePlayQueue::getTrack 0 Oct 02 20:31:12 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 20:31:12 volumio volumio[1271]: info: CoreCommandRouter::volumioPushState Oct 02 20:31:12 volumio volumio[1271]: info: CoreStateMachine::pushState Oct 02 20:31:12 volumio volumio[1271]: info: CoreCommandRouter::volumioPushState Oct 02 20:31:12 volumio volumio[1271]: info: ControllerMpd::pushState Oct 02 20:31:12 volumio volumio[1271]: info: CoreCommandRouter::servicePushState Oct 02 20:31:12 volumio volumio[1271]: info: CorePlayQueue::getTrack 0 Oct 02 20:31:12 volumio volumio[1271]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"DeepFM","artist":"(#1 - 17600/512) DEEP FM - amgradio.ru","album":null,"uri":"http://shout.amgradio.ru:80/DeepFM","trackType":""} Oct 02 20:31:12 volumio volumio[1271]: verbose: CURRENT POSITION 0 Oct 02 20:31:12 volumio volumio[1271]: info: CoreStateMachine::syncState stateService play Oct 02 20:31:12 volumio volumio[1271]: info: CoreStateMachine::syncState currentStatus play Oct 02 20:31:12 volumio volumio[1271]: info: Received an update from plugin. extracting info from payload Oct 02 20:31:12 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Oct 02 20:31:12 volumio volumio[1271]: info: CoreStateMachine::pushState Oct 02 20:31:12 volumio volumio[1271]: info: CorePlayQueue::getTrack 0 Oct 02 20:31:12 volumio volumio[1271]: info: CoreCommandRouter::volumioPushState Oct 02 20:31:12 volumio volumio[1271]: info: CoreStateMachine::pushState Oct 02 20:31:12 volumio volumio[1271]: info: CoreCommandRouter::volumioPushState Oct 02 20:31:12 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:12.039+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" state=STATUS_PLAYING positionMs=260 volume=50 Oct 02 20:31:12 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:12.039+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" id=http://shout.amgradio.ru:80/DeepFM title="DEEP FM - amgradio.ru" Oct 02 20:31:12 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:12.042+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" state=STATUS_PLAYING positionMs=260 volume=50 Oct 02 20:31:12 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:12.042+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" state=STATUS_PLAYING positionMs=260 volume=50 Oct 02 20:31:12 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:12.043+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" id=http://shout.amgradio.ru:80/DeepFM title="DEEP FM - amgradio.ru" Oct 02 20:31:12 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:12.043+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" state=STATUS_PLAYING positionMs=260 volume=50 Oct 02 20:31:12 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:12.043+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" id=http://shout.amgradio.ru:80/DeepFM title="DEEP FM - amgradio.ru" Oct 02 20:31:12 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:12.043+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" id=http://shout.amgradio.ru:80/DeepFM title="DEEP FM - amgradio.ru" Oct 02 20:31:12 volumio volumio[1271]: info: ------------------------------ 42ms Oct 02 20:31:12 volumio volumio[1271]: info: ------------------------------ 42ms Oct 02 20:31:12 volumio volumio[1271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Oct 02 20:31:12 volumio volumio[1271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Oct 02 20:31:12 volumio volumio[1271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Oct 02 20:31:12 volumio volumio[1271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Oct 02 20:31:12 volumio volumio[1271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Oct 02 20:31:12 volumio volumio[1271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Oct 02 20:31:12 volumio volumio[1271]: info: Oct 02 20:31:12 volumio volumio[1271]: ---------------------------- MPD announces system playlist update Oct 02 20:31:12 volumio volumio[1271]: info: Ignoring MPD Status Update Oct 02 20:31:12 volumio volumio[1271]: info: Oct 02 20:31:12 volumio volumio[1271]: ---------------------------- MPD announces state update: player Oct 02 20:31:12 volumio volumio[1271]: info: ControllerMpd::getState Oct 02 20:31:12 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand status Oct 02 20:31:12 volumio volumio[1271]: info: Oct 02 20:31:12 volumio volumio[1271]: ---------------------------- MPD announces system playlist update Oct 02 20:31:12 volumio volumio[1271]: info: Ignoring MPD Status Update Oct 02 20:31:12 volumio volumio[1271]: info: Oct 02 20:31:12 volumio volumio[1271]: ---------------------------- MPD announces state update: player Oct 02 20:31:12 volumio volumio[1271]: info: ControllerMpd::getState Oct 02 20:31:12 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand status Oct 02 20:31:12 volumio volumio[1271]: info: ------------------------------ 22ms Oct 02 20:31:12 volumio volumio[1271]: info: sendMpdCommand status took 20 milliseconds Oct 02 20:31:12 volumio volumio[1271]: info: ------------------------------ 20ms Oct 02 20:31:12 volumio volumio[1271]: info: sendMpdCommand status took 18 milliseconds Oct 02 20:31:12 volumio volumio[1271]: verbose: ControllerMpd::parseState Oct 02 20:31:12 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 02 20:31:12 volumio volumio[1271]: verbose: ControllerMpd::parseState Oct 02 20:31:12 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 02 20:31:12 volumio volumio[1271]: info: sendMpdCommand playlistinfo took 25 milliseconds Oct 02 20:31:12 volumio volumio[1271]: info: sendMpdCommand playlistinfo took 26 milliseconds Oct 02 20:31:12 volumio volumio[1271]: verbose: ControllerMpd::parseTrackInfo Oct 02 20:31:12 volumio volumio[1271]: verbose: ControllerMpd::parseTrackInfo Oct 02 20:31:12 volumio volumio[1271]: info: ControllerMpd::pushState Oct 02 20:31:12 volumio volumio[1271]: info: CoreCommandRouter::servicePushState Oct 02 20:31:12 volumio volumio[1271]: info: CorePlayQueue::getTrack 0 Oct 02 20:31:12 volumio volumio[1271]: verbose: STATE SERVICE {"status":"play","position":0,"seek":977,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"OKASSUS - STRANDED","artist":null,"album":null,"uri":"http://shout.amgradio.ru:80/DeepFM","trackType":""} Oct 02 20:31:12 volumio volumio[1271]: verbose: CURRENT POSITION 0 Oct 02 20:31:12 volumio volumio[1271]: info: CoreStateMachine::syncState stateService play Oct 02 20:31:12 volumio volumio[1271]: info: CoreStateMachine::syncState currentStatus play Oct 02 20:31:12 volumio volumio[1271]: info: Received an update from plugin. extracting info from payload Oct 02 20:31:12 volumio volumio[1271]: info: CoreStateMachine::pushState Oct 02 20:31:12 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 20:31:12 volumio volumio[1271]: info: CoreCommandRouter::volumioPushState Oct 02 20:31:12 volumio volumio[1271]: info: CoreStateMachine::pushState Oct 02 20:31:12 volumio volumio[1271]: info: CoreCommandRouter::volumioPushState Oct 02 20:31:12 volumio volumio[1271]: info: ControllerMpd::pushState Oct 02 20:31:12 volumio volumio[1271]: info: CoreCommandRouter::servicePushState Oct 02 20:31:12 volumio volumio[1271]: info: CorePlayQueue::getTrack 0 Oct 02 20:31:12 volumio volumio[1271]: verbose: STATE SERVICE {"status":"play","position":0,"seek":977,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"OKASSUS - STRANDED","artist":null,"album":null,"uri":"http://shout.amgradio.ru:80/DeepFM","trackType":""} Oct 02 20:31:12 volumio volumio[1271]: verbose: CURRENT POSITION 0 Oct 02 20:31:12 volumio volumio[1271]: info: CoreStateMachine::syncState stateService play Oct 02 20:31:12 volumio volumio[1271]: info: CoreStateMachine::syncState currentStatus play Oct 02 20:31:12 volumio volumio[1271]: info: Received an update from plugin. extracting info from payload Oct 02 20:31:12 volumio volumio[1271]: info: CoreStateMachine::pushState Oct 02 20:31:12 volumio volumio[1271]: info: CoreCommandRouter::volumioPushState Oct 02 20:31:12 volumio volumio[1271]: info: CoreStateMachine::pushState Oct 02 20:31:12 volumio volumio[1271]: info: CoreCommandRouter::volumioPushState Oct 02 20:31:12 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:12.183+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" state=STATUS_PLAYING positionMs=260 volume=50 Oct 02 20:31:12 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:12.184+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" id=http://shout.amgradio.ru:80/DeepFM title="OKASSUS - STRANDED" Oct 02 20:31:12 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:12.184+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" state=STATUS_PLAYING positionMs=260 volume=50 Oct 02 20:31:12 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:12.184+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" id=http://shout.amgradio.ru:80/DeepFM title="OKASSUS - STRANDED" Oct 02 20:31:12 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:12.186+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" state=STATUS_PLAYING positionMs=260 volume=50 Oct 02 20:31:12 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:12.186+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" id=http://shout.amgradio.ru:80/DeepFM title="OKASSUS - STRANDED" Oct 02 20:31:12 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:12.188+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" state=STATUS_PLAYING positionMs=260 volume=50 Oct 02 20:31:12 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:12.188+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" id=http://shout.amgradio.ru:80/DeepFM title="OKASSUS - STRANDED" Oct 02 20:31:12 volumio volumio[1271]: info: ------------------------------ 70ms Oct 02 20:31:12 volumio volumio[1271]: info: ------------------------------ 68ms Oct 02 20:31:12 volumio volumio[1271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Oct 02 20:31:12 volumio volumio[1271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Oct 02 20:31:12 volumio volumio[1271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Oct 02 20:31:12 volumio volumio[1271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Oct 02 20:31:12 volumio volumio[1271]: info: touch_display: Setting screensaver timeout to 0 seconds. Oct 02 20:31:12 volumio volumio[1271]: info: SoloistConnect: open /data/soloist/cache/cache/5a/5a7f5749386f542ec02c28dcadd8d868982aa926.file 3666303 bytes over 191s = 153 kbps -> High Oct 02 20:31:13 volumio volumio[1271]: info: Preload queue cleared Oct 02 20:31:13 volumio volumio[1271]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::ClearQueue Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::stop Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::stPlaybackTimer Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::updateTrackBlock Oct 02 20:31:13 volumio volumio[1271]: info: CorePlayQueue::getTrackBlock Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::pushState Oct 02 20:31:13 volumio volumio[1271]: info: CorePlayQueue::getTrack 0 Oct 02 20:31:13 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 20:31:13 volumio volumio[1271]: info: CoreCommandRouter::volumioPushState Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::serviceStop Oct 02 20:31:13 volumio volumio[1271]: info: CorePlayQueue::getTrack 0 Oct 02 20:31:13 volumio volumio[1271]: info: CoreCommandRouter::serviceStop Oct 02 20:31:13 volumio volumio[1271]: info: [1790962273577] ControllerWebradio::stop Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand stop Oct 02 20:31:13 volumio volumio[1271]: info: CorePlayQueue::clearPlayQueue Oct 02 20:31:13 volumio volumio[1271]: info: CorePlayQueue::saveQueue Oct 02 20:31:13 volumio volumio[1271]: info: CoreCommandRouter::volumioPushQueue Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::addQueueItems Oct 02 20:31:13 volumio volumio[1271]: info: CorePlayQueue::addQueueItems Oct 02 20:31:13 volumio volumio[1271]: info: Preload queue cleared Oct 02 20:31:13 volumio volumio[1271]: info: Adding Item to queue: http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99555531 Oct 02 20:31:13 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 02 20:31:13 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:13.579+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" state=STATUS_STOPPED positionMs=0 volume=50 Oct 02 20:31:13 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:13.579+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" id="http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99555531" title="DEEP FM - amgradio.ru" Oct 02 20:31:13 volumio volumio[1271]: info: CoreCommandRouter::volumioPushQueue Oct 02 20:31:13 volumio volumio[1271]: info: CorePlayQueue::saveQueue Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::updateTrackBlock Oct 02 20:31:13 volumio volumio[1271]: info: CorePlayQueue::getTrackBlock Oct 02 20:31:13 volumio volumio[1271]: info: CoreCommandRouter::volumioPlay Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::play index 0 Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::stop Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::play index undefined Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 02 20:31:13 volumio volumio[1271]: info: CorePlayQueue::getTrack 0 Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::startPlaybackTimer Oct 02 20:31:13 volumio volumio[1271]: info: CorePlayQueue::getTrack 0 Oct 02 20:31:13 volumio volumio[1271]: info: [1790962273596] ControllerWebradio::clearAddPlayTrack Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand stop Oct 02 20:31:13 volumio volumio[1271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Oct 02 20:31:13 volumio volumio[1271]: info: Oct 02 20:31:13 volumio volumio[1271]: ---------------------------- MPD announces state update: player Oct 02 20:31:13 volumio volumio[1271]: info: sendMpdCommand stop took 35 milliseconds Oct 02 20:31:13 volumio volumio[1271]: info: ControllerMpd::getState Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand status Oct 02 20:31:13 volumio volumio[1271]: info: sendMpdCommand stop took 16 milliseconds Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand clear Oct 02 20:31:13 volumio volumio[1271]: info: Oct 02 20:31:13 volumio volumio[1271]: ---------------------------- MPD announces system playlist update Oct 02 20:31:13 volumio volumio[1271]: info: Ignoring MPD Status Update Oct 02 20:31:13 volumio volumio[1271]: info: sendMpdCommand status took 3 milliseconds Oct 02 20:31:13 volumio volumio[1271]: info: sendMpdCommand clear took 3 milliseconds Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::parseState Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99555531" Oct 02 20:31:13 volumio volumio[1271]: info: Oct 02 20:31:13 volumio volumio[1271]: ---------------------------- MPD announces state update: player Oct 02 20:31:13 volumio volumio[1271]: info: ControllerMpd::getState Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand status Oct 02 20:31:13 volumio volumio[1271]: error: updateQueue error: null Oct 02 20:31:13 volumio volumio[1271]: info: ------------------------------ 17ms Oct 02 20:31:13 volumio volumio[1271]: info: sendMpdCommand playlistinfo took 17 milliseconds Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::parseTrackInfo Oct 02 20:31:13 volumio volumio[1271]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Oct 02 20:31:13 volumio volumio[1271]: info: ------------------------------ 23ms Oct 02 20:31:13 volumio volumio[1271]: info: touch_display: Setting screensaver timeout to 3600 seconds. Oct 02 20:31:13 volumio volumio[1271]: info: Oct 02 20:31:13 volumio volumio[1271]: ---------------------------- MPD announces system playlist update Oct 02 20:31:13 volumio volumio[1271]: info: Ignoring MPD Status Update Oct 02 20:31:13 volumio volumio[1271]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99555531" took 174 milliseconds Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand play Oct 02 20:31:13 volumio volumio[1271]: info: sendMpdCommand status took 162 milliseconds Oct 02 20:31:13 volumio volumio[1271]: info: ------------------------------ 2ms Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::parseState Oct 02 20:31:13 volumio volumio[1271]: info: ControllerMpd::pushState Oct 02 20:31:13 volumio volumio[1271]: info: CoreCommandRouter::servicePushState Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::pushState Oct 02 20:31:13 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 20:31:13 volumio volumio[1271]: info: CoreCommandRouter::volumioPushState Oct 02 20:31:13 volumio volumio[1271]: info: CorePlayQueue::getTrack 0 Oct 02 20:31:13 volumio volumio[1271]: 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} Oct 02 20:31:13 volumio volumio[1271]: verbose: CURRENT POSITION 0 Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::syncState stateService stop Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::syncState currentStatus stop Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::pushState Oct 02 20:31:13 volumio volumio[1271]: info: CoreCommandRouter::volumioPushState Oct 02 20:31:13 volumio volumio[1271]: info: No code Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::pushState Oct 02 20:31:13 volumio volumio[1271]: info: CoreCommandRouter::volumioPushState Oct 02 20:31:13 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:13.800+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" state=STATUS_PLAYING positionMs=182 volume=50 Oct 02 20:31:13 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:13.800+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" id=http://shout.amgradio.ru:80/DeepFM title="OKASSUS - STRANDED" Oct 02 20:31:13 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:13.801+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" state=STATUS_PLAYING positionMs=182 volume=50 Oct 02 20:31:13 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:13.802+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" id=http://shout.amgradio.ru:80/DeepFM title="OKASSUS - STRANDED" Oct 02 20:31:13 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:13.802+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" state=STATUS_PLAYING positionMs=182 volume=50 Oct 02 20:31:13 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:13.804+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" id=http://shout.amgradio.ru:80/DeepFM title="OKASSUS - STRANDED" Oct 02 20:31:13 volumio volumio[1271]: info: ------------------------------ 188ms Oct 02 20:31:13 volumio volumio[1271]: info: Oct 02 20:31:13 volumio volumio[1271]: ---------------------------- MPD announces system playlist update Oct 02 20:31:13 volumio volumio[1271]: info: Ignoring MPD Status Update Oct 02 20:31:13 volumio volumio[1271]: info: sendMpdCommand play took 29 milliseconds Oct 02 20:31:13 volumio volumio[1271]: info: ------------------------------ 3ms Oct 02 20:31:13 volumio volumio[1271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Oct 02 20:31:13 volumio volumio[1271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Oct 02 20:31:13 volumio volumio[1271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Oct 02 20:31:13 volumio volumio[1271]: info: Oct 02 20:31:13 volumio volumio[1271]: ---------------------------- MPD announces state update: player Oct 02 20:31:13 volumio volumio[1271]: info: ControllerMpd::getState Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand status Oct 02 20:31:13 volumio volumio[1271]: info: Oct 02 20:31:13 volumio volumio[1271]: ---------------------------- MPD announces state update: player Oct 02 20:31:13 volumio volumio[1271]: info: ControllerMpd::getState Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand status Oct 02 20:31:13 volumio volumio[1271]: info: Oct 02 20:31:13 volumio volumio[1271]: ---------------------------- MPD announces state update: player Oct 02 20:31:13 volumio volumio[1271]: info: sendMpdCommand status took 4 milliseconds Oct 02 20:31:13 volumio volumio[1271]: info: ControllerMpd::getState Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand status Oct 02 20:31:13 volumio volumio[1271]: info: sendMpdCommand status took 3 milliseconds Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::parseState Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::parseState Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 02 20:31:13 volumio volumio[1271]: info: Oct 02 20:31:13 volumio volumio[1271]: ---------------------------- MPD announces state update: player Oct 02 20:31:13 volumio volumio[1271]: info: ControllerMpd::getState Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand status Oct 02 20:31:13 volumio volumio[1271]: info: sendMpdCommand status took 9 milliseconds Oct 02 20:31:13 volumio volumio[1271]: info: sendMpdCommand playlistinfo took 9 milliseconds Oct 02 20:31:13 volumio volumio[1271]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::parseState Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::parseTrackInfo Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::parseTrackInfo Oct 02 20:31:13 volumio volumio[1271]: info: ControllerMpd::pushState Oct 02 20:31:13 volumio volumio[1271]: info: CoreCommandRouter::servicePushState Oct 02 20:31:13 volumio volumio[1271]: info: CorePlayQueue::getTrack 0 Oct 02 20:31:13 volumio volumio[1271]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"DeepFM","artist":"(#1 - 17600/512) DEEP FM - amgradio.ru","album":null,"uri":"http://shout.amgradio.ru:80/DeepFM","trackType":""} Oct 02 20:31:13 volumio volumio[1271]: verbose: CURRENT POSITION 0 Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::syncState stateService play Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::syncState currentStatus stop Oct 02 20:31:13 volumio volumio[1271]: info: ControllerMpd::pushState Oct 02 20:31:13 volumio volumio[1271]: info: CoreCommandRouter::servicePushState Oct 02 20:31:13 volumio volumio[1271]: info: CorePlayQueue::getTrack 0 Oct 02 20:31:13 volumio volumio[1271]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"DeepFM","artist":"(#1 - 17600/512) DEEP FM - amgradio.ru","album":null,"uri":"http://shout.amgradio.ru:80/DeepFM","trackType":""} Oct 02 20:31:13 volumio volumio[1271]: verbose: CURRENT POSITION 0 Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::syncState stateService play Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::syncState currentStatus play Oct 02 20:31:13 volumio volumio[1271]: info: Received an update from plugin. extracting info from payload Oct 02 20:31:13 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::pushState Oct 02 20:31:13 volumio volumio[1271]: info: CorePlayQueue::getTrack 0 Oct 02 20:31:13 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 20:31:13 volumio volumio[1271]: info: CoreCommandRouter::volumioPushState Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::pushState Oct 02 20:31:13 volumio volumio[1271]: info: CoreCommandRouter::volumioPushState Oct 02 20:31:13 volumio volumio[1271]: info: ------------------------------ 27ms Oct 02 20:31:13 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:13.922+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" state=STATUS_PLAYING positionMs=0 volume=50 Oct 02 20:31:13 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:13.923+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" id=http://shout.amgradio.ru:80/DeepFM title="DEEP FM - amgradio.ru" Oct 02 20:31:13 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:13.923+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" state=STATUS_PLAYING positionMs=0 volume=50 Oct 02 20:31:13 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:13.925+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" id=http://shout.amgradio.ru:80/DeepFM title="DEEP FM - amgradio.ru" Oct 02 20:31:13 volumio volumio[1271]: info: ------------------------------ 35ms Oct 02 20:31:13 volumio volumio[1271]: info: Oct 02 20:31:13 volumio volumio[1271]: ---------------------------- MPD announces system playlist update Oct 02 20:31:13 volumio volumio[1271]: info: Ignoring MPD Status Update Oct 02 20:31:13 volumio volumio[1271]: info: Oct 02 20:31:13 volumio volumio[1271]: ---------------------------- MPD announces state update: player Oct 02 20:31:13 volumio volumio[1271]: info: sendMpdCommand status took 27 milliseconds Oct 02 20:31:13 volumio volumio[1271]: info: ControllerMpd::getState Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand status Oct 02 20:31:13 volumio volumio[1271]: info: sendMpdCommand playlistinfo took 24 milliseconds Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::parseState Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::parseTrackInfo Oct 02 20:31:13 volumio volumio[1271]: info: ControllerMpd::pushState Oct 02 20:31:13 volumio volumio[1271]: info: CoreCommandRouter::servicePushState Oct 02 20:31:13 volumio volumio[1271]: info: CorePlayQueue::getTrack 0 Oct 02 20:31:13 volumio volumio[1271]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"OKASSUS - STRANDED","artist":null,"album":null,"uri":"http://shout.amgradio.ru:80/DeepFM","trackType":""} Oct 02 20:31:13 volumio volumio[1271]: verbose: CURRENT POSITION 0 Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::syncState stateService play Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::syncState currentStatus play Oct 02 20:31:13 volumio volumio[1271]: info: Received an update from plugin. extracting info from payload Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::pushState Oct 02 20:31:13 volumio volumio[1271]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 02 20:31:13 volumio volumio[1271]: info: CoreCommandRouter::volumioPushState Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::pushState Oct 02 20:31:13 volumio volumio[1271]: info: CoreCommandRouter::volumioPushState Oct 02 20:31:13 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:13.950+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" state=STATUS_PLAYING positionMs=0 volume=50 Oct 02 20:31:13 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:13.953+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" state=STATUS_PLAYING positionMs=0 volume=50 Oct 02 20:31:13 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:13.955+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" id=http://shout.amgradio.ru:80/DeepFM title="OKASSUS - STRANDED" Oct 02 20:31:13 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:13.955+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" id=http://shout.amgradio.ru:80/DeepFM title="OKASSUS - STRANDED" Oct 02 20:31:13 volumio volumio[1271]: info: ------------------------------ 64ms Oct 02 20:31:13 volumio volumio[1271]: info: Oct 02 20:31:13 volumio volumio[1271]: ---------------------------- MPD announces system playlist update Oct 02 20:31:13 volumio volumio[1271]: info: Ignoring MPD Status Update Oct 02 20:31:13 volumio volumio[1271]: info: Oct 02 20:31:13 volumio volumio[1271]: ---------------------------- MPD announces state update: player Oct 02 20:31:13 volumio volumio[1271]: info: ControllerMpd::getState Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand status Oct 02 20:31:13 volumio volumio[1271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Oct 02 20:31:13 volumio volumio[1271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Oct 02 20:31:13 volumio volumio[1271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Oct 02 20:31:13 volumio volumio[1271]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Oct 02 20:31:13 volumio volumio[1271]: info: touch_display: Setting screensaver timeout to 0 seconds. Oct 02 20:31:13 volumio volumio[1271]: info: ------------------------------ 61ms Oct 02 20:31:13 volumio volumio[1271]: info: sendMpdCommand status took 60 milliseconds Oct 02 20:31:13 volumio volumio[1271]: info: sendMpdCommand playlistinfo took 60 milliseconds Oct 02 20:31:13 volumio volumio[1271]: info: ------------------------------ 23ms Oct 02 20:31:13 volumio volumio[1271]: info: sendMpdCommand status took 21 milliseconds Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::parseState Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::parseTrackInfo Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::parseState Oct 02 20:31:13 volumio volumio[1271]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 02 20:31:13 volumio volumio[1271]: info: ControllerMpd::pushState Oct 02 20:31:13 volumio volumio[1271]: info: CoreCommandRouter::servicePushState Oct 02 20:31:13 volumio volumio[1271]: info: CorePlayQueue::getTrack 0 Oct 02 20:31:13 volumio volumio[1271]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"OKASSUS - STRANDED","artist":null,"album":null,"uri":"http://shout.amgradio.ru:80/DeepFM","trackType":""} Oct 02 20:31:13 volumio volumio[1271]: verbose: CURRENT POSITION 0 Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::syncState stateService play Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::syncState currentStatus play Oct 02 20:31:13 volumio volumio[1271]: info: Received an update from plugin. extracting info from payload Oct 02 20:31:13 volumio volumio[1271]: info: CoreStateMachine::pushState Oct 02 20:31:13 volumio volumio[1271]: info: CoreCommandRouter::volumioPushState Oct 02 20:31:14 volumio volumio[1271]: info: CoreStateMachine::pushState Oct 02 20:31:14 volumio volumio[1271]: info: CoreCommandRouter::volumioPushState Oct 02 20:31:14 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:14.006+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" state=STATUS_PLAYING positionMs=0 volume=50 Oct 02 20:31:14 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:14.006+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" id=http://shout.amgradio.ru:80/DeepFM title="OKASSUS - STRANDED" Oct 02 20:31:14 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:14.007+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" state=STATUS_PLAYING positionMs=0 volume=50 Oct 02 20:31:14 volumio volumio5-onboarding[1599]: time=2026-10-02T20:31:14.007+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.17:39804 @ 0x33f6240" id=http://shout.amgradio.ru:80/DeepFM title="OKASSUS - STRANDED" Oct 02 20:31:14 volumio volumio[1271]: info: ------------------------------ 109ms Oct 02 20:31:14 volumio volumio[1271]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 02 20:31:14 volumio volumio[1271]: Error: write EPROTO C07BB7B6:error:0A000438:SSL routines:ssl3_read_bytes:tlsv1 alert internal error:../deps/openssl/openssl/ssl/record/rec_layer_s3.c:1586:SSL alert number 80 Oct 02 20:31:14 volumio volumio[1271]: at WriteWrap.onWriteComplete [as oncomplete] (node:internal/stream_base_commons:94:16) { Oct 02 20:31:14 volumio volumio[1271]: errno: -71, Oct 02 20:31:14 volumio volumio[1271]: code: 'EPROTO', Oct 02 20:31:14 volumio volumio[1271]: syscall: 'write' Oct 02 20:31:14 volumio volumio[1271]: } Oct 02 20:31:14 volumio volumio[1271]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 02 20:31:14 volumio sudo[18218]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-02 20:30' Oct 02 20:31:14 volumio sudo[18218]: 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"