Feb 26 16:37:06 schiit systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 96. Feb 26 16:37:06 schiit systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 26 16:37:06 schiit systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 26 16:37:06 schiit upmpdcli[4410]: Could not open config: /tmp/upmpdcli.conf Feb 26 16:37:06 schiit systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 26 16:37:06 schiit systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 26 16:37:10 schiit volumio[1370]: info: CoreCommandRouter::volumioGetState Feb 26 16:37:10 schiit volumio[1370]: info: CorePlayQueue::getTrack 7 Feb 26 16:37:10 schiit volumio[1370]: info: CoreCommandRouter::volumioGetState Feb 26 16:37:10 schiit volumio[1370]: info: CorePlayQueue::getTrack 7 Feb 26 16:37:10 schiit volumio[1370]: info: Currently active: mpd Feb 26 16:37:10 schiit volumio[1370]: info: Stopping currently active service Feb 26 16:37:10 schiit volumio[1370]: info: CoreCommandRouter::volumioStop Feb 26 16:37:10 schiit volumio[1370]: info: CoreStateMachine::stop Feb 26 16:37:10 schiit volumio[1370]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 16:37:10 schiit volumio[1370]: info: CoreStateMachine::stPlaybackTimer Feb 26 16:37:10 schiit volumio[1370]: info: CoreStateMachine::updateTrackBlock Feb 26 16:37:10 schiit volumio[1370]: info: CorePlayQueue::getTrackBlock Feb 26 16:37:10 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:10 schiit volumio[1370]: info: CorePlayQueue::getTrack 7 Feb 26 16:37:10 schiit volumio[1370]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:37:10 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:10 schiit volumio[1370]: info: CoreStateMachine::serviceStop Feb 26 16:37:10 schiit volumio[1370]: info: CorePlayQueue::getTrack 7 Feb 26 16:37:10 schiit volumio[1370]: info: CoreCommandRouter::serviceStop Feb 26 16:37:10 schiit volumio[1370]: info: ControllerMpd::stop Feb 26 16:37:10 schiit volumio[1370]: verbose: ControllerMpd::sendMpdCommand stop Feb 26 16:37:10 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:10.854-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_STOPPED positionMs=0 volume=100 Feb 26 16:37:10 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:10.854-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id="mnt/USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/08 Soniquete.flac" title=Soniquete Feb 26 16:37:10 schiit volumio[1370]: info: Feb 26 16:37:10 schiit volumio[1370]: ---------------------------- MPD announces state update: player Feb 26 16:37:10 schiit volumio[1370]: info: sendMpdCommand stop took 10 milliseconds Feb 26 16:37:10 schiit volumio[1370]: info: ControllerMpd::getState Feb 26 16:37:10 schiit volumio[1370]: verbose: ControllerMpd::sendMpdCommand status Feb 26 16:37:10 schiit volumio[1370]: info: TidalConnect Active Feb 26 16:37:10 schiit volumio[1370]: info: CoreCommandRouter::volumioGetState Feb 26 16:37:10 schiit volumio[1370]: info: CorePlayQueue::getTrack 7 Feb 26 16:37:10 schiit volumio[1370]: info: Currently active: mpd Feb 26 16:37:10 schiit volumio[1370]: info: Setting Volatile state to tidalconnect Feb 26 16:37:10 schiit volumio[1370]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 16:37:10 schiit volumio[1370]: info: CoreCommandRouter::servicePushState Feb 26 16:37:10 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:10 schiit volumio[1370]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:37:10 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:10 schiit volumio[1370]: info: CoreCommandRouter::servicePushState Feb 26 16:37:10 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:10 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:10 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:10.870-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_PAUSED positionMs=0 volume=100 Feb 26 16:37:10 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:10.870-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id= title=Soniquete Feb 26 16:37:10 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:10.872-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_PAUSED positionMs=0 volume=100 Feb 26 16:37:10 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:10.872-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id= title=Soniquete Feb 26 16:37:10 schiit volumio[1370]: info: sendMpdCommand status took 12 milliseconds Feb 26 16:37:10 schiit volumio[1370]: verbose: ControllerMpd::parseState Feb 26 16:37:10 schiit volumio[1370]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 16:37:10 schiit volumio[1370]: info: sendMpdCommand playlistinfo took 5 milliseconds Feb 26 16:37:10 schiit volumio[1370]: verbose: ControllerMpd::parseTrackInfo Feb 26 16:37:10 schiit volumio[1370]: info: ControllerMpd::pushState Feb 26 16:37:10 schiit volumio[1370]: info: CoreCommandRouter::servicePushState Feb 26 16:37:10 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:10 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:10 schiit volumio[1370]: info: CorePlayQueue::getTrack 7 Feb 26 16:37:10 schiit volumio[1370]: 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":"Soniquete","artist":"Al Di Meola, John McLaughlin and Paco de Lucía","album":"Saturday Night in San Francisco: Live 12.6.80 (Expanded Edition)","uri":"USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/08 Soniquete.flac","trackType":"flac"} Feb 26 16:37:10 schiit volumio[1370]: verbose: CURRENT POSITION 7 Feb 26 16:37:10 schiit volumio[1370]: info: CoreStateMachine::syncState stateService stop Feb 26 16:37:10 schiit volumio[1370]: info: CoreStateMachine::syncState currentStatus pause Feb 26 16:37:10 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:10 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:10 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:10.886-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_PAUSED positionMs=0 volume=100 Feb 26 16:37:10 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:10.886-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id= title=Soniquete Feb 26 16:37:10 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:10.886-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_PAUSED positionMs=0 volume=100 Feb 26 16:37:10 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:10.887-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id= title=Soniquete Feb 26 16:37:10 schiit volumio[1370]: info: ------------------------------ 26ms Feb 26 16:37:11 schiit vtcs[1900]: [2026-02-26 16:37:11.152] [tisoc] [warning] [PlaybackControllerImpl.cpp:498] Illegal state:1 Feb 26 16:37:11 schiit volumio[1370]: info: Pushing metadata Feb 26 16:37:11 schiit volumio[1370]: info: CoreCommandRouter::servicePushState Feb 26 16:37:11 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:11 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:11 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:11.528-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_PAUSED positionMs=0 volume=100 Feb 26 16:37:11 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:11.528-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id= title=Soniquete Feb 26 16:37:11 schiit volumio[1370]: info: CoreCommandRouter::servicePushState Feb 26 16:37:11 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:11 schiit volumio[1370]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:37:11 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:11 schiit volumio[1370]: info: CoreCommandRouter::servicePushState Feb 26 16:37:11 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:11 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:11 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:11.536-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_PAUSED positionMs=52650 volume=100 Feb 26 16:37:11 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:11.536-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id= title=Soniquete Feb 26 16:37:11 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:11.537-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_PAUSED positionMs=52650 volume=100 Feb 26 16:37:11 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:11.537-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id= title=Soniquete Feb 26 16:37:11 schiit vtcs[1900]: [close:85] Entering Feb 26 16:37:11 schiit vtcs[1900]: [close:100] Exiting Feb 26 16:37:11 schiit volumio[1370]: info: Pushing metadata Feb 26 16:37:11 schiit volumio[1370]: info: CoreCommandRouter::servicePushState Feb 26 16:37:11 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:11 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:11 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:11.731-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_PAUSED positionMs=52650 volume=100 Feb 26 16:37:11 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:11.732-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id= title=Soniquete Feb 26 16:37:11 schiit vtcs[1900]: [close:85] Entering Feb 26 16:37:11 schiit vtcs[1900]: [close:100] Exiting Feb 26 16:37:11 schiit vtcs[1900]: [open:50] Opening with sample rate: 192000, type: 3 Feb 26 16:37:11 schiit volumio[1370]: info: CoreCommandRouter::servicePushState Feb 26 16:37:11 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:11 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:11 schiit volumio[1370]: info: CoreCommandRouter::servicePushState Feb 26 16:37:11 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:11 schiit volumio[1370]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:37:11 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:11 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:11.936-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_PAUSED positionMs=52650 volume=100 Feb 26 16:37:11 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:11.936-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id= title=Soniquete Feb 26 16:37:11 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:11.938-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_PAUSED positionMs=0 volume=100 Feb 26 16:37:11 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:11.939-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id= title=Soniquete Feb 26 16:37:11 schiit vtcs[1900]: [2026-02-26 16:37:11.975] [tisoc] [warning] [flac_decoder.cpp:302] FLACDecoder::error_callback FLAC__STREAM_DECODER_ERROR_STATUS_LOST_SYNC Feb 26 16:37:11 schiit vtcs[1900]: [2026-02-26 16:37:11.975] [tisoc] [warning] [flac_decoder.cpp:302] FLACDecoder::error_callback FLAC__STREAM_DECODER_ERROR_STATUS_BAD_HEADER Feb 26 16:37:11 schiit vtcs[1900]: [2026-02-26 16:37:11.975] [tisoc] [warning] [flac_decoder.cpp:302] FLACDecoder::error_callback FLAC__STREAM_DECODER_ERROR_STATUS_LOST_SYNC Feb 26 16:37:13 schiit vtcs[1900]: [start:106] Entering Feb 26 16:37:13 schiit vtcs[1900]: [start:113] Reopening PCM device... Feb 26 16:37:13 schiit volumio[1370]: info: CoreCommandRouter::servicePushState Feb 26 16:37:13 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:13 schiit volumio[1370]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:37:13 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:13 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:13.050-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_PLAYING positionMs=21 volume=100 Feb 26 16:37:13 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:13.050-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id= title=Soniquete Feb 26 16:37:13 schiit vtcs[1900]: [start:115] PCM opened successfully. Feb 26 16:37:13 schiit vtcs[1900]: [start:120] Exiting Feb 26 16:37:13 schiit vtcs[1900]: [feedThread:223] Entering Feb 26 16:37:13 schiit volumio[1370]: info: CoreCommandRouter::servicePushState Feb 26 16:37:13 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:13 schiit volumio[1370]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:37:13 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:13 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:13.429-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_PLAYING positionMs=521 volume=100 Feb 26 16:37:13 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:13.429-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id= title=Soniquete Feb 26 16:37:20 schiit vtcs[1900]: [pause:147] Entering Feb 26 16:37:20 schiit volumio[1370]: info: CoreCommandRouter::servicePushState Feb 26 16:37:20 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:20 schiit volumio[1370]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:37:20 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:20 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:20.199-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_PAUSED positionMs=7096 volume=100 Feb 26 16:37:20 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:20.199-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id= title=Soniquete Feb 26 16:37:20 schiit vtcs[1900]: [feedThread:276] Exiting Feb 26 16:37:20 schiit vtcs[1900]: [pause:161] Exiting Feb 26 16:37:21 schiit systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 97. Feb 26 16:37:21 schiit systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 26 16:37:22 schiit systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 26 16:37:22 schiit upmpdcli[4449]: Could not open config: /tmp/upmpdcli.conf Feb 26 16:37:22 schiit systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 26 16:37:22 schiit systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 26 16:37:23 schiit volumio[1370]: info: Preload queue cleared Feb 26 16:37:23 schiit volumio[1370]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 26 16:37:23 schiit volumio[1370]: info: CoreStateMachine::ClearQueue Feb 26 16:37:23 schiit volumio[1370]: info: CoreStateMachine::stop Feb 26 16:37:23 schiit volumio[1370]: info: CoreStateMachine::serviceStop Feb 26 16:37:23 schiit volumio[1370]: info: CoreCommandRouter::serviceStop Feb 26 16:37:23 schiit volumio[1370]: info: CorePlayQueue::clearPlayQueue Feb 26 16:37:23 schiit volumio[1370]: info: CorePlayQueue::saveQueue Feb 26 16:37:23 schiit volumio[1370]: info: CoreCommandRouter::volumioPushQueue Feb 26 16:37:23 schiit vtcs[1900]: [close:85] Entering Feb 26 16:37:23 schiit vtcs[1900]: [close:100] Exiting Feb 26 16:37:23 schiit volumio[1370]: info: CoreStateMachine::addQueueItems Feb 26 16:37:23 schiit volumio[1370]: info: CorePlayQueue::addQueueItems Feb 26 16:37:23 schiit volumio[1370]: info: Preload queue cleared Feb 26 16:37:23 schiit volumio[1370]: info: Adding Item to queue: music-library/USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/01 Bill Graham Introduction.flac Feb 26 16:37:23 schiit volumio[1370]: info: Using cached record of: music-library/USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/01 Bill Graham Introduction.flac Feb 26 16:37:23 schiit volumio[1370]: info: Adding Item to queue: music-library/USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/02 Splendido Sundance.flac Feb 26 16:37:23 schiit volumio[1370]: info: Using cached record of: music-library/USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/02 Splendido Sundance.flac Feb 26 16:37:23 schiit volumio[1370]: info: Adding Item to queue: music-library/USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/03 One Word.flac Feb 26 16:37:23 schiit volumio[1370]: info: Using cached record of: music-library/USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/03 One Word.flac Feb 26 16:37:23 schiit volumio[1370]: info: Adding Item to queue: music-library/USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/04 Trilogy Suite.flac Feb 26 16:37:23 schiit volumio[1370]: info: Using cached record of: music-library/USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/04 Trilogy Suite.flac Feb 26 16:37:23 schiit volumio[1370]: info: Adding Item to queue: music-library/USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/05 Monasterio de Sal.flac Feb 26 16:37:23 schiit volumio[1370]: info: Using cached record of: music-library/USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/05 Monasterio de Sal.flac Feb 26 16:37:23 schiit volumio[1370]: info: Adding Item to queue: music-library/USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/06 El Pañuelo.flac Feb 26 16:37:23 schiit volumio[1370]: info: Using cached record of: music-library/USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/06 El Pañuelo.flac Feb 26 16:37:23 schiit volumio[1370]: info: Adding Item to queue: music-library/USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/07 Meeting of the Spirits.flac Feb 26 16:37:23 schiit volumio[1370]: info: Using cached record of: music-library/USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/07 Meeting of the Spirits.flac Feb 26 16:37:23 schiit volumio[1370]: info: Adding Item to queue: music-library/USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/08 Soniquete.flac Feb 26 16:37:23 schiit volumio[1370]: info: Using cached record of: music-library/USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/08 Soniquete.flac Feb 26 16:37:23 schiit volumio[1370]: info: CoreCommandRouter::volumioPushQueue Feb 26 16:37:23 schiit volumio[1370]: info: CorePlayQueue::saveQueue Feb 26 16:37:23 schiit volumio[1370]: info: CoreStateMachine::updateTrackBlock Feb 26 16:37:23 schiit volumio[1370]: info: CorePlayQueue::getTrackBlock Feb 26 16:37:23 schiit volumio[1370]: info: CoreCommandRouter::volumioPlay Feb 26 16:37:23 schiit volumio[1370]: verbose: UNSET VOLATILE: Service: tidalconnect Feb 26 16:37:23 schiit volumio[1370]: info: unSetVolatile called Feb 26 16:37:23 schiit volumio[1370]: info: Relinquishing Volumio State to another service Feb 26 16:37:23 schiit vtcs[1900]: [2026-02-26 16:37:23.386] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE Feb 26 16:37:23 schiit volumio[1370]: info: CoreStateMachine::play index 7 Feb 26 16:37:23 schiit volumio[1370]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 16:37:23 schiit volumio[1370]: info: CoreStateMachine::stop Feb 26 16:37:23 schiit volumio[1370]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 16:37:23 schiit volumio[1370]: info: CoreStateMachine::updateTrackBlock Feb 26 16:37:23 schiit volumio[1370]: info: CorePlayQueue::getTrackBlock Feb 26 16:37:23 schiit volumio[1370]: info: CoreStateMachine::stPlaybackTimer Feb 26 16:37:23 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:23 schiit volumio[1370]: info: CorePlayQueue::getTrack 7 Feb 26 16:37:23 schiit volumio[1370]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:37:23 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:23 schiit volumio[1370]: info: CoreStateMachine::serviceStop Feb 26 16:37:23 schiit volumio[1370]: info: CorePlayQueue::getTrack 7 Feb 26 16:37:23 schiit volumio[1370]: info: CoreCommandRouter::serviceStop Feb 26 16:37:23 schiit volumio[1370]: info: ControllerMpd::stop Feb 26 16:37:23 schiit volumio[1370]: verbose: ControllerMpd::sendMpdCommand stop Feb 26 16:37:23 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:23.394-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_STOPPED positionMs=0 volume=100 Feb 26 16:37:23 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:23.394-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id="mnt/USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/08 Soniquete.flac" title=Soniquete Feb 26 16:37:23 schiit volumio[1370]: info: PlaybackInactive Feb 26 16:37:23 schiit volumio[1370]: info: Device Session is_active: true Feb 26 16:37:23 schiit volumio[1370]: info: DeviceInactive Feb 26 16:37:23 schiit volumio[1370]: info: Relinquishing Volumio State Feb 26 16:37:23 schiit volumio[1370]: info: sendMpdCommand stop took 7 milliseconds Feb 26 16:37:23 schiit volumio[1370]: info: CoreStateMachine::play index undefined Feb 26 16:37:23 schiit volumio[1370]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 16:37:23 schiit volumio[1370]: info: CorePlayQueue::getTrack 7 Feb 26 16:37:23 schiit volumio[1370]: info: CoreStateMachine::startPlaybackTimer Feb 26 16:37:23 schiit volumio[1370]: info: CorePlayQueue::getTrack 7 Feb 26 16:37:23 schiit volumio[1370]: info: CoreCommandRouter::volumioGetVisibleSources Feb 26 16:37:23 schiit volumio[1370]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 26 16:37:23 schiit volumio[1370]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 26 16:37:23 schiit volumio[1370]: verbose: ControllerMpd::clearAddPlayTracks USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/08 Soniquete.flac Feb 26 16:37:23 schiit volumio[1370]: verbose: ControllerMpd::sendMpdCommand stop Feb 26 16:37:23 schiit volumio[1370]: info: sendMpdCommand stop took 1 milliseconds Feb 26 16:37:23 schiit volumio[1370]: verbose: ControllerMpd::sendMpdCommand clear Feb 26 16:37:23 schiit volumio[1370]: info: Feb 26 16:37:23 schiit volumio[1370]: ---------------------------- MPD announces system playlist update Feb 26 16:37:23 schiit volumio[1370]: info: Ignoring MPD Status Update Feb 26 16:37:23 schiit volumio[1370]: info: sendMpdCommand clear took 0 milliseconds Feb 26 16:37:23 schiit volumio[1370]: verbose: ControllerMpd::sendMpdCommand add "USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/08 Soniquete.flac" Feb 26 16:37:23 schiit volumio[1370]: error: updateQueue error: null Feb 26 16:37:23 schiit volumio[1370]: info: ------------------------------ 1ms Feb 26 16:37:23 schiit volumio[1370]: info: sendMpdCommand add "USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/08 Soniquete.flac" took 1 milliseconds Feb 26 16:37:23 schiit volumio[1370]: verbose: ControllerMpd::sendMpdCommand play Feb 26 16:37:23 schiit volumio[1370]: info: Feb 26 16:37:23 schiit volumio[1370]: ---------------------------- MPD announces system playlist update Feb 26 16:37:23 schiit volumio[1370]: info: Ignoring MPD Status Update Feb 26 16:37:23 schiit volumio[1370]: info: sendMpdCommand play took 1 milliseconds Feb 26 16:37:23 schiit volumio[1370]: info: ------------------------------ 1ms Feb 26 16:37:23 schiit volumio[1370]: info: Feb 26 16:37:23 schiit volumio[1370]: ---------------------------- MPD announces state update: player Feb 26 16:37:23 schiit volumio[1370]: info: ControllerMpd::getState Feb 26 16:37:23 schiit volumio[1370]: verbose: ControllerMpd::sendMpdCommand status Feb 26 16:37:23 schiit vtcs[1900]: [2026-02-26 16:37:23] [info] asio async_shutdown error: asio.misc:2 (End of file) Feb 26 16:37:23 schiit volumio[1370]: info: Feb 26 16:37:23 schiit volumio[1370]: ---------------------------- MPD announces state update: player Feb 26 16:37:23 schiit volumio[1370]: info: sendMpdCommand status took 5 milliseconds Feb 26 16:37:23 schiit volumio[1370]: info: ControllerMpd::getState Feb 26 16:37:23 schiit volumio[1370]: verbose: ControllerMpd::sendMpdCommand status Feb 26 16:37:23 schiit volumio[1370]: verbose: ControllerMpd::parseState Feb 26 16:37:23 schiit volumio[1370]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 16:37:23 schiit volumio[1370]: info: sendMpdCommand status took 1 milliseconds Feb 26 16:37:23 schiit volumio[1370]: verbose: ControllerMpd::parseState Feb 26 16:37:23 schiit volumio[1370]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 16:37:23 schiit volumio[1370]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 26 16:37:23 schiit volumio[1370]: info: sendMpdCommand playlistinfo took 0 milliseconds Feb 26 16:37:23 schiit volumio[1370]: verbose: ControllerMpd::parseTrackInfo Feb 26 16:37:23 schiit volumio[1370]: verbose: ControllerMpd::parseTrackInfo Feb 26 16:37:23 schiit volumio[1370]: info: ControllerMpd::pushState Feb 26 16:37:23 schiit volumio[1370]: info: CoreCommandRouter::servicePushState Feb 26 16:37:23 schiit volumio[1370]: info: CorePlayQueue::getTrack 7 Feb 26 16:37:23 schiit volumio[1370]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":407,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Soniquete","artist":"Al Di Meola, John McLaughlin and Paco de Lucía","album":"Saturday Night in San Francisco: Live 12.6.80 (Expanded Edition)","uri":"USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/08 Soniquete.flac","trackType":"flac"} Feb 26 16:37:23 schiit volumio[1370]: verbose: CURRENT POSITION 7 Feb 26 16:37:23 schiit volumio[1370]: info: CoreStateMachine::syncState stateService play Feb 26 16:37:23 schiit volumio[1370]: info: CoreStateMachine::syncState currentStatus stop Feb 26 16:37:23 schiit volumio[1370]: info: ControllerMpd::pushState Feb 26 16:37:23 schiit volumio[1370]: info: CoreCommandRouter::servicePushState Feb 26 16:37:23 schiit volumio[1370]: info: CorePlayQueue::getTrack 7 Feb 26 16:37:23 schiit volumio[1370]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":407,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Soniquete","artist":"Al Di Meola, John McLaughlin and Paco de Lucía","album":"Saturday Night in San Francisco: Live 12.6.80 (Expanded Edition)","uri":"USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/08 Soniquete.flac","trackType":"flac"} Feb 26 16:37:23 schiit volumio[1370]: verbose: CURRENT POSITION 7 Feb 26 16:37:23 schiit volumio[1370]: info: CoreStateMachine::syncState stateService play Feb 26 16:37:23 schiit volumio[1370]: info: CoreStateMachine::syncState currentStatus play Feb 26 16:37:23 schiit volumio[1370]: info: Received an update from plugin. extracting info from payload Feb 26 16:37:23 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:23 schiit volumio[1370]: info: CorePlayQueue::getTrack 7 Feb 26 16:37:23 schiit volumio[1370]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:37:23 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:23 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:23 schiit volumio[1370]: info: CorePlayQueue::getTrack 7 Feb 26 16:37:23 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:23 schiit volumio[1370]: info: ------------------------------ 11ms Feb 26 16:37:23 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:23.416-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:37:23 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:23.416-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id="mnt/USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/08 Soniquete.flac" title=Soniquete Feb 26 16:37:23 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:23.417-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_PLAYING positionMs=0 volume=100 Feb 26 16:37:23 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:23.417-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id="mnt/USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/08 Soniquete.flac" title=Soniquete Feb 26 16:37:23 schiit volumio[1370]: info: ------------------------------ 14ms Feb 26 16:37:30 schiit volumio[1370]: info: CoreCommandRouter::volumioPause Feb 26 16:37:30 schiit volumio[1370]: info: CoreStateMachine::pause Feb 26 16:37:30 schiit volumio[1370]: info: CoreStateMachine::stPlaybackTimer Feb 26 16:37:30 schiit volumio[1370]: info: CoreStateMachine::servicePause Feb 26 16:37:30 schiit volumio[1370]: info: CorePlayQueue::getTrack 7 Feb 26 16:37:30 schiit volumio[1370]: info: CoreCommandRouter::servicePause Feb 26 16:37:30 schiit volumio[1370]: info: ControllerMpd::pause Feb 26 16:37:30 schiit volumio[1370]: verbose: ControllerMpd::sendMpdCommand pause Feb 26 16:37:30 schiit volumio[1370]: info: Feb 26 16:37:30 schiit volumio[1370]: ---------------------------- MPD announces state update: player Feb 26 16:37:30 schiit volumio[1370]: info: sendMpdCommand pause took 1 milliseconds Feb 26 16:37:30 schiit volumio[1370]: info: ControllerMpd::getState Feb 26 16:37:30 schiit volumio[1370]: verbose: ControllerMpd::sendMpdCommand status Feb 26 16:37:30 schiit volumio[1370]: info: sendMpdCommand status took 0 milliseconds Feb 26 16:37:30 schiit volumio[1370]: verbose: ControllerMpd::parseState Feb 26 16:37:30 schiit volumio[1370]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 16:37:30 schiit volumio[1370]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 26 16:37:30 schiit volumio[1370]: verbose: ControllerMpd::parseTrackInfo Feb 26 16:37:30 schiit volumio[1370]: info: ControllerMpd::pushState Feb 26 16:37:30 schiit volumio[1370]: info: CoreCommandRouter::servicePushState Feb 26 16:37:30 schiit volumio[1370]: info: CorePlayQueue::getTrack 7 Feb 26 16:37:30 schiit volumio[1370]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":7745,"duration":407,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"4914 Kbps","isStreaming":false,"title":"Soniquete","artist":"Al Di Meola, John McLaughlin and Paco de Lucía","album":"Saturday Night in San Francisco: Live 12.6.80 (Expanded Edition)","uri":"USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/08 Soniquete.flac","trackType":"flac"} Feb 26 16:37:30 schiit volumio[1370]: verbose: CURRENT POSITION 7 Feb 26 16:37:30 schiit volumio[1370]: info: CoreStateMachine::syncState stateService pause Feb 26 16:37:30 schiit volumio[1370]: info: CoreStateMachine::syncState currentStatus pause Feb 26 16:37:30 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:30 schiit volumio[1370]: info: CorePlayQueue::getTrack 7 Feb 26 16:37:30 schiit volumio[1370]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:37:30 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:30 schiit volumio[1370]: info: CoreStateMachine::stPlaybackTimer Feb 26 16:37:30 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:30.214-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_PAUSED positionMs=6789 volume=100 Feb 26 16:37:30 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:30.214-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id="mnt/USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/08 Soniquete.flac" title=Soniquete Feb 26 16:37:30 schiit volumio[1370]: info: ------------------------------ 7ms Feb 26 16:37:34 schiit volumio[1370]: info: CoreCommandRouter::volumioGetState Feb 26 16:37:34 schiit volumio[1370]: info: CorePlayQueue::getTrack 7 Feb 26 16:37:34 schiit volumio[1370]: info: CoreCommandRouter::volumioGetState Feb 26 16:37:34 schiit volumio[1370]: info: CorePlayQueue::getTrack 7 Feb 26 16:37:34 schiit volumio[1370]: info: Currently active: mpd Feb 26 16:37:34 schiit volumio[1370]: info: Stopping currently active service Feb 26 16:37:34 schiit volumio[1370]: info: CoreCommandRouter::volumioStop Feb 26 16:37:34 schiit volumio[1370]: info: CoreStateMachine::stop Feb 26 16:37:34 schiit volumio[1370]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 16:37:34 schiit volumio[1370]: info: CoreStateMachine::updateTrackBlock Feb 26 16:37:34 schiit volumio[1370]: info: CorePlayQueue::getTrackBlock Feb 26 16:37:34 schiit volumio[1370]: info: CoreStateMachine::stPlaybackTimer Feb 26 16:37:34 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:34 schiit volumio[1370]: info: CorePlayQueue::getTrack 7 Feb 26 16:37:34 schiit volumio[1370]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:37:34 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:34 schiit volumio[1370]: info: CoreStateMachine::serviceStop Feb 26 16:37:34 schiit volumio[1370]: info: CorePlayQueue::getTrack 7 Feb 26 16:37:34 schiit volumio[1370]: info: CoreCommandRouter::serviceStop Feb 26 16:37:34 schiit volumio[1370]: info: ControllerMpd::stop Feb 26 16:37:34 schiit volumio[1370]: verbose: ControllerMpd::sendMpdCommand stop Feb 26 16:37:34 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:34.814-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_STOPPED positionMs=0 volume=100 Feb 26 16:37:34 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:34.814-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id="mnt/USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/08 Soniquete.flac" title=Soniquete Feb 26 16:37:34 schiit volumio[1370]: info: Feb 26 16:37:34 schiit volumio[1370]: ---------------------------- MPD announces state update: player Feb 26 16:37:34 schiit volumio[1370]: info: sendMpdCommand stop took 8 milliseconds Feb 26 16:37:34 schiit volumio[1370]: info: ControllerMpd::getState Feb 26 16:37:34 schiit volumio[1370]: verbose: ControllerMpd::sendMpdCommand status Feb 26 16:37:34 schiit volumio[1370]: info: TidalConnect Active Feb 26 16:37:34 schiit volumio[1370]: info: CoreCommandRouter::volumioGetState Feb 26 16:37:34 schiit volumio[1370]: info: CorePlayQueue::getTrack 7 Feb 26 16:37:34 schiit volumio[1370]: info: Currently active: mpd Feb 26 16:37:34 schiit volumio[1370]: info: Setting Volatile state to tidalconnect Feb 26 16:37:34 schiit volumio[1370]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 16:37:34 schiit volumio[1370]: info: CoreCommandRouter::servicePushState Feb 26 16:37:34 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:34 schiit volumio[1370]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:37:34 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:34 schiit volumio[1370]: info: CoreCommandRouter::servicePushState Feb 26 16:37:34 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:34 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:34 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:34.826-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_PAUSED positionMs=0 volume=100 Feb 26 16:37:34 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:34.827-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id= title=Soniquete Feb 26 16:37:34 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:34.827-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_PAUSED positionMs=0 volume=100 Feb 26 16:37:34 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:34.827-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id= title=Soniquete Feb 26 16:37:34 schiit volumio[1370]: info: sendMpdCommand status took 10 milliseconds Feb 26 16:37:34 schiit volumio[1370]: verbose: ControllerMpd::parseState Feb 26 16:37:34 schiit volumio[1370]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 26 16:37:34 schiit volumio[1370]: info: sendMpdCommand playlistinfo took 4 milliseconds Feb 26 16:37:34 schiit volumio[1370]: verbose: ControllerMpd::parseTrackInfo Feb 26 16:37:34 schiit volumio[1370]: info: ControllerMpd::pushState Feb 26 16:37:34 schiit volumio[1370]: info: CoreCommandRouter::servicePushState Feb 26 16:37:34 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:34 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:34 schiit volumio[1370]: info: CorePlayQueue::getTrack 7 Feb 26 16:37:34 schiit volumio[1370]: 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":"Soniquete","artist":"Al Di Meola, John McLaughlin and Paco de Lucía","album":"Saturday Night in San Francisco: Live 12.6.80 (Expanded Edition)","uri":"USB/7B9F-E653/MUSIC desktop/Al Di Meola - 2022 - Saturday Night in San Francisco- Live 12.6.80 (Expanded Edition) (24bit-192kHz)/08 Soniquete.flac","trackType":"flac"} Feb 26 16:37:34 schiit volumio[1370]: verbose: CURRENT POSITION 7 Feb 26 16:37:34 schiit volumio[1370]: info: CoreStateMachine::syncState stateService stop Feb 26 16:37:34 schiit volumio[1370]: info: CoreStateMachine::syncState currentStatus pause Feb 26 16:37:34 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:34 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:34 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:34.840-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_PAUSED positionMs=0 volume=100 Feb 26 16:37:34 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:34.840-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id= title=Soniquete Feb 26 16:37:34 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:34.843-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_PAUSED positionMs=0 volume=100 Feb 26 16:37:34 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:34.843-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id= title=Soniquete Feb 26 16:37:34 schiit volumio[1370]: info: ------------------------------ 26ms Feb 26 16:37:34 schiit vtcs[1900]: [2026-02-26 16:37:34.957] [tisoc] [warning] [PlaybackControllerImpl.cpp:498] Illegal state:1 Feb 26 16:37:35 schiit volumio[1370]: info: Pushing metadata Feb 26 16:37:35 schiit volumio[1370]: info: CoreCommandRouter::servicePushState Feb 26 16:37:35 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:35 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:35 schiit volumio[1370]: info: CoreCommandRouter::servicePushState Feb 26 16:37:35 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:35 schiit volumio[1370]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:37:35 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:35 schiit volumio[1370]: info: CoreCommandRouter::servicePushState Feb 26 16:37:35 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:35 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:35 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:35.412-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_PAUSED positionMs=0 volume=100 Feb 26 16:37:35 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:35.412-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id= title=Soniquete Feb 26 16:37:35 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:35.412-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_PAUSED positionMs=7096 volume=100 Feb 26 16:37:35 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:35.412-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_PAUSED positionMs=7096 volume=100 Feb 26 16:37:35 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:35.413-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id= title=Soniquete Feb 26 16:37:35 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:35.413-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id= title=Soniquete Feb 26 16:37:35 schiit vtcs[1900]: [close:85] Entering Feb 26 16:37:35 schiit vtcs[1900]: [close:100] Exiting Feb 26 16:37:35 schiit volumio[1370]: info: Pushing metadata Feb 26 16:37:35 schiit volumio[1370]: info: CoreCommandRouter::servicePushState Feb 26 16:37:35 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:35 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:35 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:35.627-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_PAUSED positionMs=7096 volume=100 Feb 26 16:37:35 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:35.627-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id= title=Soniquete Feb 26 16:37:35 schiit volumio[1370]: info: CoreCommandRouter::servicePushState Feb 26 16:37:35 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:35 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:35 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:35.631-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_PAUSED positionMs=7096 volume=100 Feb 26 16:37:35 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:35.632-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id= title=Soniquete Feb 26 16:37:35 schiit vtcs[1900]: [close:85] Entering Feb 26 16:37:35 schiit vtcs[1900]: [close:100] Exiting Feb 26 16:37:35 schiit vtcs[1900]: [open:50] Opening with sample rate: 192000, type: 3 Feb 26 16:37:35 schiit volumio[1370]: info: CoreCommandRouter::servicePushState Feb 26 16:37:35 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:35 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:35 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:35.903-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_PAUSED positionMs=7096 volume=100 Feb 26 16:37:35 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:35.903-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id= title=Soniquete Feb 26 16:37:36 schiit vtcs[1900]: [2026-02-26 16:37:36.084] [tisoc] [warning] [flac_decoder.cpp:302] FLACDecoder::error_callback FLAC__STREAM_DECODER_ERROR_STATUS_LOST_SYNC Feb 26 16:37:37 schiit vtcs[1900]: [start:106] Entering Feb 26 16:37:37 schiit vtcs[1900]: [start:113] Reopening PCM device... Feb 26 16:37:37 schiit volumio[1370]: info: CoreCommandRouter::servicePushState Feb 26 16:37:37 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:37 schiit volumio[1370]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:37:37 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:37 schiit vtcs[1900]: [start:115] PCM opened successfully. Feb 26 16:37:37 schiit vtcs[1900]: [start:120] Exiting Feb 26 16:37:37 schiit vtcs[1900]: [feedThread:223] Entering Feb 26 16:37:37 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:37.084-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_PLAYING positionMs=21 volume=100 Feb 26 16:37:37 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:37.084-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id= title=Soniquete Feb 26 16:37:37 schiit systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 98. Feb 26 16:37:37 schiit systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 26 16:37:37 schiit systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 26 16:37:37 schiit upmpdcli[4474]: Could not open config: /tmp/upmpdcli.conf Feb 26 16:37:37 schiit systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 26 16:37:37 schiit systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 26 16:37:37 schiit volumio[1370]: info: CoreCommandRouter::servicePushState Feb 26 16:37:37 schiit volumio[1370]: info: CoreStateMachine::pushState Feb 26 16:37:37 schiit volumio[1370]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 16:37:37 schiit volumio[1370]: info: CoreCommandRouter::volumioPushState Feb 26 16:37:37 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:37.458-05:00 level=INFO msg="emitting player state changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" state=STATUS_PLAYING positionMs=521 volume=100 Feb 26 16:37:37 schiit volumio5-onboarding[1748]: time=2026-02-26T16:37:37.458-05:00 level=INFO msg="emitting player metadata changed event" component=server peer="10.0.0.31:33958 @ 0x2c1bad0" id= title=Soniquete Feb 26 16:37:52 schiit systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 99. Feb 26 16:37:52 schiit systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 26 16:37:52 schiit systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 26 16:37:52 schiit upmpdcli[4504]: Could not open config: /tmp/upmpdcli.conf Feb 26 16:37:52 schiit systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 26 16:37:52 schiit systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 26 16:38:07 schiit systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 100. Feb 26 16:38:07 schiit systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 26 16:38:07 schiit systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 26 16:38:07 schiit upmpdcli[4524]: Could not open config: /tmp/upmpdcli.conf Feb 26 16:38:07 schiit systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 26 16:38:07 schiit systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 26 16:38:16 schiit volumio[1370]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 26 16:38:16 schiit volumio[1370]: TypeError: Cannot read properties of null (reading 'slice') Feb 26 16:38:16 schiit volumio[1370]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41) Feb 26 16:38:16 schiit volumio[1370]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7) Feb 26 16:38:16 schiit volumio[1370]: at Object.onceWrapper (node:events:629:26) Feb 26 16:38:16 schiit volumio[1370]: at ClientRequest.emit (node:events:514:28) Feb 26 16:38:16 schiit volumio[1370]: at HTTPParser.parserOnIncomingClient [as onIncoming] (node:_http_client:693:27) Feb 26 16:38:16 schiit volumio[1370]: at HTTPParser.parserOnHeadersComplete (node:_http_common:119:17) Feb 26 16:38:16 schiit volumio[1370]: at TLSSocket.socketOnData (node:_http_client:535:22) Feb 26 16:38:16 schiit volumio[1370]: at TLSSocket.emit (node:events:514:28) Feb 26 16:38:16 schiit volumio[1370]: at addChunk (node:internal/streams/readable:343:12) Feb 26 16:38:16 schiit volumio[1370]: at readableAddChunk (node:internal/streams/readable:316:9) Feb 26 16:38:16 schiit volumio[1370]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 26 16:38:16 schiit sudo[4549]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-26 16:37' Feb 26 16:38:16 schiit sudo[4549]: 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="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"