-- Logs begin at Thu 2025-08-07 14:48:22 WIB, end at Sat 2025-08-30 21:22:21 WIB. -- Aug 30 21:21:26 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Aug 30 21:21:26 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 30 21:21:26 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 30 21:21:26 zenix-nat volumio[3419]: info: Discovery: Getting this device information Aug 30 21:21:26 zenix-nat volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 21:21:26 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 1 Aug 30 21:21:26 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 30 21:21:26 zenix-nat volumio[3419]: info: browseTIDALUri took 724 milliseconds Aug 30 21:21:27 zenix-nat volumio[3419]: info: Preload queue cleared Aug 30 21:21:27 zenix-nat volumio[3419]: info: Preload queue cleared Aug 30 21:21:29 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Aug 30 21:21:30 zenix-nat volumio[3419]: info: browseTIDALUri took 778 milliseconds Aug 30 21:21:30 zenix-nat volumio[3419]: info: Preload queue cleared Aug 30 21:21:30 zenix-nat volumio[3419]: info: Preload queue cleared Aug 30 21:21:31 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Aug 30 21:21:33 zenix-nat volumiologrotate[2849]: ls: cannot access '/var/log/samba/log.wb-ZENIX': No such file or directory Aug 30 21:21:33 zenix-nat volumiologrotate[2849]: ls: cannot access 'NAT': No such file or directory Aug 30 21:21:34 zenix-nat volumio[3419]: info: browseTIDALUri took 2687 milliseconds Aug 30 21:21:34 zenix-nat volumio[3419]: info: Preload queue cleared Aug 30 21:21:34 zenix-nat volumio[3419]: info: Preloading song: tidal://song/373339873 Aug 30 21:21:34 zenix-nat volumio[3419]: info: Preloading song: tidal://song/421087379 Aug 30 21:21:34 zenix-nat volumio[3419]: info: Preloading song: tidal://song/96461945 Aug 30 21:21:34 zenix-nat volumio[3419]: info: Preloading song: tidal://song/218740662 Aug 30 21:21:34 zenix-nat volumio[3419]: info: Preloading song: tidal://song/170594746 Aug 30 21:21:34 zenix-nat volumio[3419]: info: Exploding uri tidal://song/373339873 in service tidal Aug 30 21:21:34 zenix-nat volumio[3419]: info: Exploding uri tidal://song/421087379 in service tidal Aug 30 21:21:34 zenix-nat volumio[3419]: info: Exploding uri tidal://song/96461945 in service tidal Aug 30 21:21:34 zenix-nat volumio[3419]: info: Exploding uri tidal://song/218740662 in service tidal Aug 30 21:21:34 zenix-nat volumio[3419]: info: Exploding uri tidal://song/170594746 in service tidal Aug 30 21:21:35 zenix-nat volumio[3419]: info: explodeTIDALUri took 596 milliseconds Aug 30 21:21:35 zenix-nat volumio[3419]: info: explodeTIDALUri took 651 milliseconds Aug 30 21:21:35 zenix-nat volumio[3419]: info: explodeTIDALUri took 565 milliseconds Aug 30 21:21:35 zenix-nat volumio[3419]: info: explodeTIDALUri took 827 milliseconds Aug 30 21:21:35 zenix-nat volumio[3419]: error: TIDAL Browse Error: failed to get track: got 404: {"status":404,"subStatus":2001,"userMessage":"Track [373339873] not found"} Aug 30 21:21:35 zenix-nat volumio[3419]: error: Commandrouter: Cannot explode uri tidal://song/373339873 from service tidal: failed to get track: got 404: {"status":404,"subStatus":2001,"userMessage":"Track [373339873] not found"} Aug 30 21:21:35 zenix-nat volumio[3419]: info: explodeTIDALUri took 777 milliseconds Aug 30 21:21:36 zenix-nat volumio[3419]: Searching all installed plugins Aug 30 21:21:36 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 30 21:21:36 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: , search Aug 30 21:21:36 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: mpd , search Aug 30 21:21:36 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Aug 30 21:21:36 zenix-nat volumio[3419]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Aug 30 21:21:36 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: webradio , search Aug 30 21:21:36 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: tidal , search Aug 30 21:21:37 zenix-nat volumio[3419]: Searching all installed plugins Aug 30 21:21:37 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 30 21:21:37 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: , search Aug 30 21:21:37 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: mpd , search Aug 30 21:21:37 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Aug 30 21:21:37 zenix-nat volumio[3419]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Aug 30 21:21:37 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: webradio , search Aug 30 21:21:37 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: tidal , search Aug 30 21:21:37 zenix-nat volumio[3419]: info: An error occurred while querying SHOUTCAST Aug 30 21:21:37 zenix-nat volumio[3419]: info: searchTIDALUri took 879 milliseconds Aug 30 21:21:37 zenix-nat volumio[3419]: info: search took 881 milliseconds Aug 30 21:21:38 zenix-nat volumio[3419]: info: All search sources collected, pushing search results Aug 30 21:21:38 zenix-nat volumio[3419]: info: searchTIDALUri took 975 milliseconds Aug 30 21:21:38 zenix-nat volumio[3419]: info: search took 976 milliseconds Aug 30 21:21:38 zenix-nat volumio[3419]: info: All search sources collected, pushing search results Aug 30 21:21:39 zenix-nat volumio[3419]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/volumio/app/plugins/miscellanea/albumart/icons/fa-tags.svg' Aug 30 21:21:39 zenix-nat volumio[3419]: Searching all installed plugins Aug 30 21:21:39 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 30 21:21:39 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: , search Aug 30 21:21:39 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: mpd , search Aug 30 21:21:39 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Aug 30 21:21:39 zenix-nat volumio[3419]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Aug 30 21:21:39 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: webradio , search Aug 30 21:21:39 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: tidal , search Aug 30 21:21:40 zenix-nat volumio[3419]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/volumio/app/plugins/miscellanea/albumart/icons/fa-tags.svg' Aug 30 21:21:40 zenix-nat volumio[3419]: info: searchTIDALUri took 806 milliseconds Aug 30 21:21:40 zenix-nat volumio[3419]: info: search took 807 milliseconds Aug 30 21:21:40 zenix-nat volumio[3419]: info: All search sources collected, pushing search results Aug 30 21:21:41 zenix-nat volumio[3419]: Searching all installed plugins Aug 30 21:21:41 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 30 21:21:41 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: , search Aug 30 21:21:41 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: mpd , search Aug 30 21:21:41 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Aug 30 21:21:41 zenix-nat volumio[3419]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Aug 30 21:21:41 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: webradio , search Aug 30 21:21:41 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: tidal , search Aug 30 21:21:41 zenix-nat volumio[3419]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/volumio/app/plugins/miscellanea/albumart/icons/fa-tags.svg' Aug 30 21:21:42 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 1 Aug 30 21:21:42 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 2 Aug 30 21:21:42 zenix-nat volumio[3419]: info: Prefetching next song Aug 30 21:21:42 zenix-nat volumio[3419]: info: DOING PREFETCH IN MPD Aug 30 21:21:42 zenix-nat volumio[3419]: verbose: ControllerMpd::sendMpdCommand add "USB/CORSAIR/01.CD TEST OFFICIAL/Canton 50 Years . Reference Check Vol. 2/03. Famous Monsters.flac" Aug 30 21:21:42 zenix-nat volumio[3419]: info: Aug 30 21:21:42 zenix-nat volumio[3419]: ---------------------------- MPD announces system playlist update Aug 30 21:21:42 zenix-nat volumio[3419]: info: Ignoring MPD Status Update Aug 30 21:21:42 zenix-nat volumio[3419]: info: sendMpdCommand add "USB/CORSAIR/01.CD TEST OFFICIAL/Canton 50 Years . Reference Check Vol. 2/03. Famous Monsters.flac" took 5 milliseconds Aug 30 21:21:42 zenix-nat volumio[3419]: verbose: ControllerMpd::sendMpdCommand consume 1 Aug 30 21:21:42 zenix-nat volumio[3419]: info: ------------------------------ 5ms Aug 30 21:21:42 zenix-nat volumio[3419]: info: sendMpdCommand consume 1 took 3 milliseconds Aug 30 21:21:42 zenix-nat volumio[3419]: Searching all installed plugins Aug 30 21:21:42 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 30 21:21:42 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: , search Aug 30 21:21:42 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: mpd , search Aug 30 21:21:42 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Aug 30 21:21:42 zenix-nat volumio[3419]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Aug 30 21:21:42 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: webradio , search Aug 30 21:21:42 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: tidal , search Aug 30 21:21:44 zenix-nat volumio[3419]: info: An error occurred while querying SHOUTCAST Aug 30 21:21:45 zenix-nat volumio[3419]: info: searchTIDALUri took 3920 milliseconds Aug 30 21:21:45 zenix-nat volumio[3419]: info: search took 3922 milliseconds Aug 30 21:21:46 zenix-nat volumio[3419]: error: Search in plugin webradio timed out Aug 30 21:21:46 zenix-nat volumio[3419]: info: All search sources collected, pushing search results Aug 30 21:21:46 zenix-nat volumio[3419]: info: CoreStateMachine::startPlaybackTimer Aug 30 21:21:46 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 2 Aug 30 21:21:47 zenix-nat volumio[3419]: info: CoreStateMachine::pushState Aug 30 21:21:47 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 2 Aug 30 21:21:47 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:21:47 zenix-nat volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 21:21:47 zenix-nat volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 21:21:47 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 2 Aug 30 21:21:47 zenix-nat volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 21:21:47 zenix-nat volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 21:21:47 zenix-nat volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 21:21:47 zenix-nat volumio[3419]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Aug 30 21:21:47 zenix-nat volumio[3419]: info: Updating RAAT Signal Path Aug 30 21:21:47 zenix-nat volumio[3419]: info: Aug 30 21:21:47 zenix-nat volumio[3419]: ---------------------------- MPD announces system playlist update Aug 30 21:21:47 zenix-nat volumio[3419]: info: Ignoring MPD Status Update Aug 30 21:21:47 zenix-nat volumio[3419]: info: Aug 30 21:21:47 zenix-nat volumio[3419]: ---------------------------- MPD announces state update: player Aug 30 21:21:47 zenix-nat volumio[3419]: info: ControllerMpd::getState Aug 30 21:21:47 zenix-nat volumio[3419]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:21:47 zenix-nat volumio[3419]: info: ------------------------------ 6ms Aug 30 21:21:47 zenix-nat volumio[3419]: info: sendMpdCommand status took 4 milliseconds Aug 30 21:21:47 zenix-nat volumio[3419]: verbose: ControllerMpd::parseState Aug 30 21:21:47 zenix-nat volumio[3419]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:21:47 zenix-nat volumio[3419]: info: sendMpdCommand playlistinfo took 2 milliseconds Aug 30 21:21:47 zenix-nat volumio[3419]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:21:47 zenix-nat volumio[3419]: info: ControllerMpd::pushState Aug 30 21:21:47 zenix-nat volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 21:21:47 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 2 Aug 30 21:21:47 zenix-nat volumio[3419]: verbose: STATE SERVICE {"status":"play","position":0,"seek":80,"duration":397,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2119 Kbps","isStreaming":false,"title":"Famous Monsters","artist":"Chromatics","album":"Reference Check Vol. 2 | 50 Years Canton","uri":"USB/CORSAIR/01.CD TEST OFFICIAL/Canton 50 Years . Reference Check Vol. 2/03. Famous Monsters.flac","trackType":"flac"} Aug 30 21:21:47 zenix-nat volumio[3419]: verbose: CURRENT POSITION 2 Aug 30 21:21:47 zenix-nat volumio[3419]: info: CoreStateMachine::syncState stateService play Aug 30 21:21:47 zenix-nat volumio[3419]: info: CoreStateMachine::syncState currentStatus play Aug 30 21:21:47 zenix-nat volumio[3419]: info: Received an update from plugin. extracting info from payload Aug 30 21:21:47 zenix-nat volumio[3419]: info: CoreStateMachine::pushState Aug 30 21:21:47 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 2 Aug 30 21:21:47 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:21:47 zenix-nat volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 21:21:47 zenix-nat volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 21:21:47 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 2 Aug 30 21:21:47 zenix-nat volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 21:21:47 zenix-nat volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 21:21:47 zenix-nat volumio[3419]: info: CoreStateMachine::pushState Aug 30 21:21:47 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 2 Aug 30 21:21:47 zenix-nat volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 21:21:47 zenix-nat volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 21:21:47 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 2 Aug 30 21:21:47 zenix-nat volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 21:21:47 zenix-nat volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 21:21:47 zenix-nat volumio[3419]: info: ------------------------------ 61ms Aug 30 21:21:47 zenix-nat volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 21:21:47 zenix-nat volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 21:21:47 zenix-nat volumio[3419]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Aug 30 21:21:47 zenix-nat volumio[3419]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Aug 30 21:21:47 zenix-nat volumio[3419]: info: Updating RAAT Signal Path Aug 30 21:21:47 zenix-nat volumio[3419]: info: Updating RAAT Signal Path Aug 30 21:21:47 zenix-nat volumio[3419]: error: Search in plugin webradio timed out Aug 30 21:21:47 zenix-nat volumio[3419]: error: Search in plugin tidal timed out Aug 30 21:21:47 zenix-nat volumio[3419]: info: All search sources collected, pushing search results Aug 30 21:21:49 zenix-nat volumio[3419]: info: Executing endpoint metavolumio Aug 30 21:21:49 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Aug 30 21:21:49 zenix-nat volumio[3419]: info: Executing endpoint metavolumio Aug 30 21:21:49 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Aug 30 21:21:49 zenix-nat volumio[3419]: info: Executing endpoint metavolumio Aug 30 21:21:49 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Aug 30 21:21:53 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Aug 30 21:21:56 zenix-nat volumio[3419]: error: Failed request for metavolumio API Aug 30 21:21:56 zenix-nat volumio[3419]: error: Failed request for metavolumio API Aug 30 21:21:56 zenix-nat volumio[3419]: error: Failed request for metavolumio API Aug 30 21:21:56 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 30 21:21:56 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 30 21:21:56 zenix-nat volumio[3419]: info: Discovery: Getting this device information Aug 30 21:21:56 zenix-nat volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 21:21:56 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 2 Aug 30 21:21:56 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 30 21:22:00 zenix-nat volumio[3419]: info: searchTIDALUri took 17600 milliseconds Aug 30 21:22:00 zenix-nat volumio[3419]: info: search took 17604 milliseconds Aug 30 21:22:00 zenix-nat volumio[3419]: error: Failed search in plugin tidal: Error: Unable to resolve or reject the same promise twice Aug 30 21:22:01 zenix-nat volumio[3419]: info: browseTIDALUri took 8733 milliseconds Aug 30 21:22:01 zenix-nat volumio[3419]: info: Preload queue cleared Aug 30 21:22:01 zenix-nat volumio[3419]: info: Preload queue cleared Aug 30 21:22:04 zenix-nat volumio[3419]: error: Failed search in plugin webradio: Error: Unable to resolve or reject the same promise twice Aug 30 21:22:11 zenix-nat volumio[3419]: info: CoreCommandRouter::volumioPlay Aug 30 21:22:11 zenix-nat volumio[3419]: info: CoreStateMachine::play index 6 Aug 30 21:22:11 zenix-nat volumio[3419]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 21:22:11 zenix-nat volumio[3419]: info: CoreStateMachine::stop Aug 30 21:22:11 zenix-nat volumio[3419]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 21:22:11 zenix-nat volumio[3419]: info: CoreStateMachine::stPlaybackTimer Aug 30 21:22:11 zenix-nat volumio[3419]: info: CoreStateMachine::updateTrackBlock Aug 30 21:22:11 zenix-nat volumio[3419]: info: CorePlayQueue::getTrackBlock Aug 30 21:22:11 zenix-nat volumio[3419]: info: CoreStateMachine::pushState Aug 30 21:22:11 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 2 Aug 30 21:22:11 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:22:11 zenix-nat volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 21:22:11 zenix-nat volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 21:22:11 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 2 Aug 30 21:22:11 zenix-nat volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 21:22:11 zenix-nat volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 21:22:11 zenix-nat volumio[3419]: info: CoreStateMachine::serviceStop Aug 30 21:22:11 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 2 Aug 30 21:22:11 zenix-nat volumio[3419]: info: CoreCommandRouter::serviceStop Aug 30 21:22:11 zenix-nat volumio[3419]: info: ControllerMpd::stop Aug 30 21:22:11 zenix-nat volumio[3419]: verbose: ControllerMpd::sendMpdCommand stop Aug 30 21:22:11 zenix-nat volumio[3419]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Aug 30 21:22:11 zenix-nat volumio[3419]: info: Updating RAAT Signal Path Aug 30 21:22:11 zenix-nat volumio[3419]: info: Aug 30 21:22:11 zenix-nat volumio[3419]: ---------------------------- MPD announces state update: player Aug 30 21:22:11 zenix-nat volumio[3419]: info: sendMpdCommand stop took 69 milliseconds Aug 30 21:22:11 zenix-nat volumio[3419]: info: ControllerMpd::getState Aug 30 21:22:11 zenix-nat volumio[3419]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:22:11 zenix-nat volumio[3419]: info: CoreStateMachine::play index undefined Aug 30 21:22:11 zenix-nat volumio[3419]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 30 21:22:11 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 6 Aug 30 21:22:11 zenix-nat volumio[3419]: info: CoreStateMachine::startPlaybackTimer Aug 30 21:22:11 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 6 Aug 30 21:22:11 zenix-nat volumio[3419]: verbose: ControllerMpd::clearAddPlayTracks USB/CORSAIR/01.CD TEST OFFICIAL/Canton 50 Years . Reference Check Vol. 2/07. Walk a Mile in My Shoes.flac Aug 30 21:22:11 zenix-nat volumio[3419]: verbose: ControllerMpd::sendMpdCommand stop Aug 30 21:22:11 zenix-nat volumio[3419]: info: sendMpdCommand status took 3 milliseconds Aug 30 21:22:11 zenix-nat volumio[3419]: info: sendMpdCommand stop took 2 milliseconds Aug 30 21:22:11 zenix-nat volumio[3419]: verbose: ControllerMpd::parseState Aug 30 21:22:11 zenix-nat volumio[3419]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:22:11 zenix-nat volumio[3419]: verbose: ControllerMpd::sendMpdCommand clear Aug 30 21:22:11 zenix-nat volumio[3419]: info: Aug 30 21:22:11 zenix-nat volumio[3419]: ---------------------------- MPD announces system playlist update Aug 30 21:22:11 zenix-nat volumio[3419]: info: Ignoring MPD Status Update Aug 30 21:22:11 zenix-nat volumio[3419]: info: sendMpdCommand playlistinfo took 5 milliseconds Aug 30 21:22:11 zenix-nat volumio[3419]: info: sendMpdCommand clear took 4 milliseconds Aug 30 21:22:11 zenix-nat volumio[3419]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:22:11 zenix-nat volumio[3419]: verbose: ControllerMpd::sendMpdCommand add "USB/CORSAIR/01.CD TEST OFFICIAL/Canton 50 Years . Reference Check Vol. 2/07. Walk a Mile in My Shoes.flac" Aug 30 21:22:11 zenix-nat volumio[3419]: info: ControllerMpd::pushState Aug 30 21:22:11 zenix-nat volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 21:22:11 zenix-nat volumio[3419]: info: CoreStateMachine::pushState Aug 30 21:22:12 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 6 Aug 30 21:22:12 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:22:12 zenix-nat volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 21:22:12 zenix-nat volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 21:22:12 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 6 Aug 30 21:22:12 zenix-nat volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 21:22:12 zenix-nat volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 21:22:12 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 6 Aug 30 21:22:12 zenix-nat volumio[3419]: 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":"Famous Monsters","artist":"Chromatics","album":"Reference Check Vol. 2 | 50 Years Canton","uri":"USB/CORSAIR/01.CD TEST OFFICIAL/Canton 50 Years . Reference Check Vol. 2/03. Famous Monsters.flac","trackType":"flac"} Aug 30 21:22:12 zenix-nat volumio[3419]: verbose: CURRENT POSITION 6 Aug 30 21:22:12 zenix-nat volumio[3419]: info: CoreStateMachine::syncState stateService stop Aug 30 21:22:12 zenix-nat volumio[3419]: info: CoreStateMachine::syncState currentStatus stop Aug 30 21:22:12 zenix-nat volumio[3419]: info: CoreStateMachine::pushState Aug 30 21:22:12 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 6 Aug 30 21:22:12 zenix-nat volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 21:22:12 zenix-nat volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 21:22:12 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 6 Aug 30 21:22:12 zenix-nat volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 21:22:12 zenix-nat volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 21:22:12 zenix-nat volumio[3419]: info: No code Aug 30 21:22:12 zenix-nat volumio[3419]: info: CoreStateMachine::pushState Aug 30 21:22:12 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 6 Aug 30 21:22:12 zenix-nat volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 21:22:12 zenix-nat volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 21:22:12 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 6 Aug 30 21:22:12 zenix-nat volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 21:22:12 zenix-nat volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 21:22:12 zenix-nat volumio[3419]: info: ------------------------------ 54ms Aug 30 21:22:12 zenix-nat volumio[3419]: error: updateQueue error: null Aug 30 21:22:12 zenix-nat volumio[3419]: info: Aug 30 21:22:12 zenix-nat volumio[3419]: ---------------------------- MPD announces system playlist update Aug 30 21:22:12 zenix-nat volumio[3419]: info: Ignoring MPD Status Update Aug 30 21:22:12 zenix-nat volumio[3419]: info: ------------------------------ 47ms Aug 30 21:22:12 zenix-nat volumio[3419]: info: sendMpdCommand add "USB/CORSAIR/01.CD TEST OFFICIAL/Canton 50 Years . Reference Check Vol. 2/07. Walk a Mile in My Shoes.flac" took 45 milliseconds Aug 30 21:22:12 zenix-nat volumio[3419]: verbose: ControllerMpd::sendMpdCommand play Aug 30 21:22:12 zenix-nat volumio[3419]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Aug 30 21:22:12 zenix-nat volumio[3419]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Aug 30 21:22:12 zenix-nat volumio[3419]: info: Updating RAAT Signal Path Aug 30 21:22:12 zenix-nat volumio[3419]: info: Aug 30 21:22:12 zenix-nat volumio[3419]: ---------------------------- MPD announces state update: player Aug 30 21:22:12 zenix-nat volumio[3419]: info: ------------------------------ 33ms Aug 30 21:22:12 zenix-nat volumio[3419]: info: sendMpdCommand play took 32 milliseconds Aug 30 21:22:12 zenix-nat volumio[3419]: info: ControllerMpd::getState Aug 30 21:22:12 zenix-nat volumio[3419]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:22:12 zenix-nat volumio[3419]: info: MCU Signalled Playback Inactive Aug 30 21:22:12 zenix-nat volumio[3419]: info: Aug 30 21:22:12 zenix-nat volumio[3419]: ---------------------------- MPD announces state update: player Aug 30 21:22:12 zenix-nat volumio[3419]: info: ControllerMpd::getState Aug 30 21:22:12 zenix-nat volumio[3419]: verbose: ControllerMpd::sendMpdCommand status Aug 30 21:22:12 zenix-nat volumio[3419]: info: sendMpdCommand status took 9 milliseconds Aug 30 21:22:12 zenix-nat volumio[3419]: verbose: ControllerMpd::parseState Aug 30 21:22:12 zenix-nat volumio[3419]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:22:12 zenix-nat volumio[3419]: info: sendMpdCommand status took 19 milliseconds Aug 30 21:22:12 zenix-nat volumio[3419]: info: sendMpdCommand playlistinfo took 17 milliseconds Aug 30 21:22:12 zenix-nat volumio[3419]: verbose: ControllerMpd::parseState Aug 30 21:22:12 zenix-nat volumio[3419]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 30 21:22:12 zenix-nat volumio[3419]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:22:12 zenix-nat volumio[3419]: info: ControllerMpd::pushState Aug 30 21:22:12 zenix-nat volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 21:22:12 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 6 Aug 30 21:22:12 zenix-nat volumio[3419]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1121,"duration":283,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1414 Kbps","isStreaming":false,"title":"Walk a Mile in My Shoes","artist":"Big Daddy Wilson","album":"Reference Check Vol. 2 | 50 Years Canton","uri":"USB/CORSAIR/01.CD TEST OFFICIAL/Canton 50 Years . Reference Check Vol. 2/07. Walk a Mile in My Shoes.flac","trackType":"flac"} Aug 30 21:22:12 zenix-nat volumio[3419]: verbose: CURRENT POSITION 6 Aug 30 21:22:12 zenix-nat volumio[3419]: info: CoreStateMachine::syncState stateService play Aug 30 21:22:12 zenix-nat volumio[3419]: info: CoreStateMachine::syncState currentStatus stop Aug 30 21:22:12 zenix-nat volumio[3419]: info: ------------------------------ 40ms Aug 30 21:22:12 zenix-nat volumio[3419]: info: sendMpdCommand playlistinfo took 153 milliseconds Aug 30 21:22:12 zenix-nat volumio[3419]: verbose: ControllerMpd::parseTrackInfo Aug 30 21:22:12 zenix-nat volumio[3419]: info: ControllerMpd::pushState Aug 30 21:22:12 zenix-nat volumio[3419]: info: CoreCommandRouter::servicePushState Aug 30 21:22:12 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 6 Aug 30 21:22:12 zenix-nat volumio[3419]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":283,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1414 Kbps","isStreaming":false,"title":"Walk a Mile in My Shoes","artist":"Big Daddy Wilson","album":"Reference Check Vol. 2 | 50 Years Canton","uri":"USB/CORSAIR/01.CD TEST OFFICIAL/Canton 50 Years . Reference Check Vol. 2/07. Walk a Mile in My Shoes.flac","trackType":"flac"} Aug 30 21:22:12 zenix-nat volumio[3419]: verbose: CURRENT POSITION 6 Aug 30 21:22:12 zenix-nat volumio[3419]: info: CoreStateMachine::syncState stateService play Aug 30 21:22:12 zenix-nat volumio[3419]: info: CoreStateMachine::syncState currentStatus play Aug 30 21:22:12 zenix-nat volumio[3419]: info: Received an update from plugin. extracting info from payload Aug 30 21:22:12 zenix-nat volumio[3419]: info: CoreStateMachine::pushState Aug 30 21:22:12 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 6 Aug 30 21:22:12 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 30 21:22:12 zenix-nat volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 21:22:12 zenix-nat volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 21:22:12 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 6 Aug 30 21:22:12 zenix-nat volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 21:22:12 zenix-nat volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 21:22:12 zenix-nat volumio[3419]: info: CoreStateMachine::pushState Aug 30 21:22:12 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 6 Aug 30 21:22:12 zenix-nat volumio[3419]: info: CoreCommandRouter::volumioPushState Aug 30 21:22:12 zenix-nat volumio[3419]: info: CoreCommandRouter::volumioGetState Aug 30 21:22:12 zenix-nat volumio[3419]: info: CorePlayQueue::getTrack 6 Aug 30 21:22:12 zenix-nat volumio[3419]: info: MRS: Pushing multiroomSync output update for this device Aug 30 21:22:12 zenix-nat volumio[3419]: info: MRS: Pushing multiroomSync output Aug 30 21:22:12 zenix-nat volumio[3419]: info: ------------------------------ 225ms Aug 30 21:22:12 zenix-nat volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 21:22:12 zenix-nat volumio[3419]: info: Signalling Playback active due to playback status change Aug 30 21:22:12 zenix-nat volumio[3419]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Aug 30 21:22:12 zenix-nat volumio[3419]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Aug 30 21:22:12 zenix-nat volumio[3419]: info: Updating RAAT Signal Path Aug 30 21:22:12 zenix-nat volumio[3419]: info: Updating RAAT Signal Path Aug 30 21:22:12 zenix-nat volumio[3419]: info: MCU Signalled Playback Active Aug 30 21:22:14 zenix-nat volumio[3419]: info: Executing endpoint metavolumio Aug 30 21:22:14 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Aug 30 21:22:14 zenix-nat volumio[3419]: info: Executing endpoint metavolumio Aug 30 21:22:14 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Aug 30 21:22:14 zenix-nat volumio[3419]: info: Executing endpoint metavolumio Aug 30 21:22:14 zenix-nat volumio[3419]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Aug 30 21:22:20 zenix-nat volumio[3419]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 30 21:22:20 zenix-nat volumio[3419]: Error: read ECONNRESET Aug 30 21:22:20 zenix-nat volumio[3419]: at TCP.onStreamRead (internal/stream_base_commons.js:209:20) { Aug 30 21:22:20 zenix-nat volumio[3419]: errno: -104, Aug 30 21:22:20 zenix-nat volumio[3419]: code: 'ECONNRESET', Aug 30 21:22:20 zenix-nat volumio[3419]: syscall: 'read' Aug 30 21:22:20 zenix-nat volumio[3419]: } Aug 30 21:22:20 zenix-nat volumio[3419]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 30 21:22:21 zenix-nat sudo[23829]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-08-30 21:21 Aug 30 21:22:21 zenix-nat sudo[23829]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="669bb6cc406bb77b11c5184fedb8a4dfd19ba4ec" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="primo2rev2" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 12:21:26 PM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Primo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Primo" VOLUMIO_HASH="0f77ca7c94b84efc5e990804c1669257"