Jan 28 21:03:00 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:00 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:00 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:00 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:00 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:00 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:00 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:00 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:00 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:00 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:00 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:00 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:00 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:00 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:00 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:00 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:00 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:00 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:00 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:00 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:00 volumio01 volumio[23098]: info: METAVOLUMIO: No new tracks added to queue, Starting fallback strategies Jan 28 21:03:00 volumio01 volumio[23098]: info: METAVOLUMIO: Infinity playback mode stopping, exhausted all strategies to continue Jan 28 21:03:01 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:01 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:01 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:01 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:01 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:01 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:01 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:01 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:01 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:01 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:01 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:01 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:01 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:01 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:01 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:01 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:01 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:01 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:01 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:01 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:01 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:01 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:01 volumio01 volumio[23098]: info: METAVOLUMIO: No new tracks added to queue, Starting fallback strategies Jan 28 21:03:01 volumio01 volumio[23098]: info: METAVOLUMIO: Infinity playback mode stopping, exhausted all strategies to continue Jan 28 21:03:02 volumio01 volumio[23098]: info: Preload queue cleared Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreStateMachine::ClearQueue Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreStateMachine::stop Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreStateMachine::stPlaybackTimer Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreStateMachine::updateTrackBlock Jan 28 21:03:02 volumio01 volumio[23098]: info: CorePlayQueue::getTrackBlock Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreStateMachine::pushState Jan 28 21:03:02 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 0 Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushState Jan 28 21:03:02 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output update for this device Jan 28 21:03:02 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:02 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 0 Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreStateMachine::serviceStop Jan 28 21:03:02 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 0 Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreCommandRouter::serviceStop Jan 28 21:03:02 volumio01 volumio[23098]: info: ControllerMpd::stop Jan 28 21:03:02 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand stop Jan 28 21:03:02 volumio01 volumio[23098]: info: CorePlayQueue::clearPlayQueue Jan 28 21:03:02 volumio01 volumio[23098]: info: CorePlayQueue::saveQueue Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushQueue Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreStateMachine::addQueueItems Jan 28 21:03:02 volumio01 volumio[23098]: info: CorePlayQueue::addQueueItems Jan 28 21:03:02 volumio01 volumio[23098]: info: Preload queue cleared Jan 28 21:03:02 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_L_refL.wav Jan 28 21:03:02 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_L_refL.wav Jan 28 21:03:02 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_LR_refL.wav Jan 28 21:03:02 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_LR_refL.wav Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushQueue Jan 28 21:03:02 volumio01 volumio[23098]: info: CorePlayQueue::saveQueue Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreStateMachine::updateTrackBlock Jan 28 21:03:02 volumio01 volumio[23098]: info: CorePlayQueue::getTrackBlock Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:02 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 0 Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPlay Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreStateMachine::play index 1 Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreStateMachine::addQueueItems Jan 28 21:03:02 volumio01 volumio[23098]: info: CorePlayQueue::addQueueItems Jan 28 21:03:02 volumio01 volumio[23098]: info: Preload queue cleared Jan 28 21:03:02 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_R_refL.wav Jan 28 21:03:02 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_R_refL.wav Jan 28 21:03:02 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/HouseCurveTestSignal.wav Jan 28 21:03:02 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/HouseCurveTestSignal.wav Jan 28 21:03:02 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_BOTH.wav Jan 28 21:03:02 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_BOTH.wav Jan 28 21:03:02 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_L.wav Jan 28 21:03:02 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_L.wav Jan 28 21:03:02 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_R.wav Jan 28 21:03:02 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_R.wav Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreStateMachine::stop Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushQueue Jan 28 21:03:02 volumio01 volumio[23098]: info: CorePlayQueue::saveQueue Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreStateMachine::play index undefined Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreStateMachine::updateTrackBlock Jan 28 21:03:02 volumio01 volumio[23098]: info: CorePlayQueue::getTrackBlock Jan 28 21:03:02 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreStateMachine::startPlaybackTimer Jan 28 21:03:02 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:02 volumio01 volumio[23098]: verbose: ControllerMpd::clearAddPlayTracks INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_LR_refL.wav Jan 28 21:03:02 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand stop Jan 28 21:03:02 volumio01 volumio[23098]: info: PeppySpectrum ---peppyspectrum status stop Jan 28 21:03:02 volumio01 volumio[23098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Jan 28 21:03:02 volumio01 volumio[23098]: info: Jan 28 21:03:02 volumio01 volumio[23098]: ---------------------------- MPD announces state update: player Jan 28 21:03:02 volumio01 volumio[23098]: info: sendMpdCommand stop took 169 milliseconds Jan 28 21:03:02 volumio01 volumio[23098]: info: ControllerMpd::getState Jan 28 21:03:02 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand status Jan 28 21:03:02 volumio01 volumio[23098]: info: sendMpdCommand stop took 77 milliseconds Jan 28 21:03:02 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand clear Jan 28 21:03:02 volumio01 volumio[23098]: info: Jan 28 21:03:02 volumio01 volumio[23098]: ---------------------------- MPD announces system playlist update Jan 28 21:03:02 volumio01 volumio[23098]: info: Ignoring MPD Status Update Jan 28 21:03:02 volumio01 volumio[23098]: info: sendMpdCommand status took 43 milliseconds Jan 28 21:03:02 volumio01 volumio[23098]: info: sendMpdCommand clear took 43 milliseconds Jan 28 21:03:02 volumio01 volumio[23098]: verbose: ControllerMpd::parseState Jan 28 21:03:02 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 21:03:02 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand add "INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_LR_refL.wav" Jan 28 21:03:02 volumio01 volumio[23098]: error: updateQueue error: null Jan 28 21:03:02 volumio01 volumio[23098]: info: Jan 28 21:03:02 volumio01 volumio[23098]: ---------------------------- MPD announces system playlist update Jan 28 21:03:02 volumio01 volumio[23098]: info: Ignoring MPD Status Update Jan 28 21:03:02 volumio01 volumio[23098]: info: ------------------------------ 5ms Jan 28 21:03:02 volumio01 volumio[23098]: info: sendMpdCommand playlistinfo took 4 milliseconds Jan 28 21:03:02 volumio01 volumio[23098]: info: sendMpdCommand add "INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_LR_refL.wav" took 4 milliseconds Jan 28 21:03:02 volumio01 volumio[23098]: verbose: ControllerMpd::parseTrackInfo Jan 28 21:03:02 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand play Jan 28 21:03:02 volumio01 volumio[23098]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Jan 28 21:03:02 volumio01 volumio[23098]: info: ------------------------------ 55ms Jan 28 21:03:02 volumio01 volumio[23098]: info: ------------------------------ 7ms Jan 28 21:03:02 volumio01 sudo[8275]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Jan 28 21:03:02 volumio01 volumio[23098]: info: sendMpdCommand play took 6 milliseconds Jan 28 21:03:02 volumio01 sudo[8275]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:02 volumio01 volumio[23098]: info: touch_display: Setting screensaver timeout to 120 seconds. Jan 28 21:03:02 volumio01 volumio[23098]: info: Jan 28 21:03:02 volumio01 volumio[23098]: ---------------------------- MPD announces state update: player Jan 28 21:03:02 volumio01 volumio[23098]: info: ControllerMpd::getState Jan 28 21:03:02 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand status Jan 28 21:03:02 volumio01 volumio[23098]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jan 28 21:03:02 volumio01 volumio[23098]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jan 28 21:03:02 volumio01 volumio[23098]: info: FusionDsp - ---- read samplerate from file: 44100 Jan 28 21:03:02 volumio01 volumio[23098]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jan 28 21:03:02 volumio01 volumio[23098]: info: Jan 28 21:03:02 volumio01 volumio[23098]: ---------------------------- MPD announces state update: player Jan 28 21:03:02 volumio01 volumio[23098]: info: sendMpdCommand status took 22 milliseconds Jan 28 21:03:02 volumio01 volumio[23098]: info: ControllerMpd::getState Jan 28 21:03:02 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand status Jan 28 21:03:02 volumio01 volumio[23098]: verbose: ControllerMpd::parseState Jan 28 21:03:02 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 21:03:02 volumio01 sudo[8275]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:02 volumio01 volumio[23098]: info: sendMpdCommand status took 17 milliseconds Jan 28 21:03:02 volumio01 volumio[23098]: info: sendMpdCommand playlistinfo took 17 milliseconds Jan 28 21:03:02 volumio01 volumio[23098]: verbose: ControllerMpd::parseState Jan 28 21:03:02 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 21:03:02 volumio01 volumio[23098]: verbose: ControllerMpd::parseTrackInfo Jan 28 21:03:02 volumio01 volumio[23098]: info: ControllerMpd::pushState Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreCommandRouter::servicePushState Jan 28 21:03:02 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:02 volumio01 volumio[23098]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":16,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"512kMeasSweep_30_to_20k_44k_PCM16_LR_refL","artist":"FusionDsp","album":"Test Signal","uri":"INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_LR_refL.wav","trackType":"wav"} Jan 28 21:03:02 volumio01 volumio[23098]: verbose: CURRENT POSITION 1 Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreStateMachine::syncState stateService play Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreStateMachine::syncState currentStatus stop Jan 28 21:03:02 volumio01 volumio[23098]: info: ------------------------------ 52ms Jan 28 21:03:02 volumio01 volumio[23098]: info: sendMpdCommand playlistinfo took 5 milliseconds Jan 28 21:03:02 volumio01 volumio[23098]: verbose: ControllerMpd::parseTrackInfo Jan 28 21:03:02 volumio01 volumio[23098]: info: ControllerMpd::pushState Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreCommandRouter::servicePushState Jan 28 21:03:02 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:02 volumio01 volumio[23098]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1214,"duration":16,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"512kMeasSweep_30_to_20k_44k_PCM16_LR_refL","artist":"FusionDsp","album":"Test Signal","uri":"INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_LR_refL.wav","trackType":"wav"} Jan 28 21:03:02 volumio01 volumio[23098]: verbose: CURRENT POSITION 1 Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreStateMachine::syncState stateService play Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreStateMachine::syncState currentStatus play Jan 28 21:03:02 volumio01 volumio[23098]: info: Received an update from plugin. extracting info from payload Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreStateMachine::pushState Jan 28 21:03:02 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushState Jan 28 21:03:02 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output update for this device Jan 28 21:03:02 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:02 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreStateMachine::pushState Jan 28 21:03:02 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushState Jan 28 21:03:02 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output update for this device Jan 28 21:03:02 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output Jan 28 21:03:02 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:02 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:02 volumio01 volumio[23098]: info: ------------------------------ 111ms Jan 28 21:03:02 volumio01 volumio[23098]: info: peppyspectrum Daemon Stop Jan 28 21:03:02 volumio01 volumio[23098]: info: PeppySpectrum ---peppyspectrum status play Jan 28 21:03:03 volumio01 volumio[23098]: info: PeppySpectrum ---peppyspectrum status play Jan 28 21:03:03 volumio01 volumio[23098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Jan 28 21:03:03 volumio01 sudo[8285]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Jan 28 21:03:03 volumio01 volumio[23098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Jan 28 21:03:03 volumio01 sudo[8285]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:03 volumio01 sudo[8287]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Jan 28 21:03:03 volumio01 sudo[8287]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:03 volumio01 systemd[1]: Started peppyspectrum.service - peppyspectrum Daemon. Jan 28 21:03:03 volumio01 sudo[8285]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:03 volumio01 volumio[23098]: info: peppyspectrum Daemon Started Jan 28 21:03:03 volumio01 sudo[8287]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:03 volumio01 volumio[23098]: info: peppyspectrum Daemon Started Jan 28 21:03:03 volumio01 volumio[23098]: info: Preload queue cleared Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreStateMachine::ClearQueue Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreStateMachine::stop Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreStateMachine::stPlaybackTimer Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreStateMachine::updateTrackBlock Jan 28 21:03:03 volumio01 volumio[23098]: info: CorePlayQueue::getTrackBlock Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreStateMachine::pushState Jan 28 21:03:03 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushState Jan 28 21:03:03 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output update for this device Jan 28 21:03:03 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:03 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreStateMachine::serviceStop Jan 28 21:03:03 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreCommandRouter::serviceStop Jan 28 21:03:03 volumio01 volumio[23098]: info: ControllerMpd::stop Jan 28 21:03:03 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand stop Jan 28 21:03:03 volumio01 volumio[23098]: info: CorePlayQueue::clearPlayQueue Jan 28 21:03:03 volumio01 volumio[23098]: info: CorePlayQueue::saveQueue Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushQueue Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreStateMachine::addQueueItems Jan 28 21:03:03 volumio01 volumio[23098]: info: CorePlayQueue::addQueueItems Jan 28 21:03:03 volumio01 volumio[23098]: info: Preload queue cleared Jan 28 21:03:03 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_L_refL.wav Jan 28 21:03:03 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_L_refL.wav Jan 28 21:03:03 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_LR_refL.wav Jan 28 21:03:03 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_LR_refL.wav Jan 28 21:03:03 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_R_refL.wav Jan 28 21:03:03 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_R_refL.wav Jan 28 21:03:03 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/HouseCurveTestSignal.wav Jan 28 21:03:03 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/HouseCurveTestSignal.wav Jan 28 21:03:03 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_BOTH.wav Jan 28 21:03:03 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_BOTH.wav Jan 28 21:03:03 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_L.wav Jan 28 21:03:03 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_L.wav Jan 28 21:03:03 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_R.wav Jan 28 21:03:03 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_R.wav Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushQueue Jan 28 21:03:03 volumio01 volumio[23098]: info: CorePlayQueue::saveQueue Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreStateMachine::updateTrackBlock Jan 28 21:03:03 volumio01 volumio[23098]: info: CorePlayQueue::getTrackBlock Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:03 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPlay Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreStateMachine::play index 6 Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreStateMachine::stop Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreStateMachine::play index undefined Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 21:03:03 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreStateMachine::startPlaybackTimer Jan 28 21:03:03 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetVisibleSources Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 21:03:03 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jan 28 21:03:03 volumio01 volumio[23098]: info: METAVOLUMIO: Retrieving similar tracks from metavolumio Jan 28 21:03:03 volumio01 volumio[23098]: verbose: ControllerMpd::clearAddPlayTracks INTERNAL/FusionDsp/tools/PinkNoise_44k_R.wav Jan 28 21:03:03 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand stop Jan 28 21:03:04 volumio01 volumio[23098]: info: PeppySpectrum ---peppyspectrum status stop Jan 28 21:03:04 volumio01 volumio[23098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Jan 28 21:03:04 volumio01 volumio[23098]: info: Jan 28 21:03:04 volumio01 volumio[23098]: ---------------------------- MPD announces state update: player Jan 28 21:03:04 volumio01 volumio[23098]: info: sendMpdCommand stop took 761 milliseconds Jan 28 21:03:04 volumio01 volumio[23098]: info: ControllerMpd::getState Jan 28 21:03:04 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand status Jan 28 21:03:04 volumio01 volumio[23098]: info: sendMpdCommand stop took 703 milliseconds Jan 28 21:03:04 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand clear Jan 28 21:03:04 volumio01 sudo[8304]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Jan 28 21:03:04 volumio01 sudo[8304]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:04 volumio01 systemd[1]: Stopping peppyspectrum.service - peppyspectrum Daemon... Jan 28 21:03:04 volumio01 systemd[1]: peppyspectrum.service: Deactivated successfully. Jan 28 21:03:04 volumio01 systemd[1]: Stopped peppyspectrum.service - peppyspectrum Daemon. Jan 28 21:03:04 volumio01 systemd[1]: peppyspectrum.service: Consumed 1.477s CPU time. Jan 28 21:03:04 volumio01 sudo[8304]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:04 volumio01 volumio[23098]: info: Jan 28 21:03:04 volumio01 volumio[23098]: ---------------------------- MPD announces system playlist update Jan 28 21:03:04 volumio01 volumio[23098]: info: Ignoring MPD Status Update Jan 28 21:03:04 volumio01 volumio[23098]: info: sendMpdCommand status took 260 milliseconds Jan 28 21:03:04 volumio01 volumio[23098]: info: sendMpdCommand clear took 259 milliseconds Jan 28 21:03:04 volumio01 volumio[23098]: verbose: ControllerMpd::parseState Jan 28 21:03:04 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 21:03:04 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand add "INTERNAL/FusionDsp/tools/PinkNoise_44k_R.wav" Jan 28 21:03:04 volumio01 volumio[23098]: info: peppyspectrum Daemon Stop Jan 28 21:03:04 volumio01 volumio[23098]: error: updateQueue error: null Jan 28 21:03:04 volumio01 volumio[23098]: info: Jan 28 21:03:04 volumio01 volumio[23098]: ---------------------------- MPD announces system playlist update Jan 28 21:03:04 volumio01 volumio[23098]: info: Ignoring MPD Status Update Jan 28 21:03:04 volumio01 volumio[23098]: info: ------------------------------ 98ms Jan 28 21:03:04 volumio01 volumio[23098]: info: sendMpdCommand playlistinfo took 92 milliseconds Jan 28 21:03:04 volumio01 volumio[23098]: info: sendMpdCommand add "INTERNAL/FusionDsp/tools/PinkNoise_44k_R.wav" took 93 milliseconds Jan 28 21:03:04 volumio01 volumio[23098]: verbose: ControllerMpd::parseTrackInfo Jan 28 21:03:04 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand play Jan 28 21:03:04 volumio01 volumio[23098]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Jan 28 21:03:04 volumio01 volumio[23098]: info: ------------------------------ 363ms Jan 28 21:03:05 volumio01 volumio[23098]: info: touch_display: Setting screensaver timeout to 120 seconds. Jan 28 21:03:05 volumio01 volumio[23098]: info: Jan 28 21:03:05 volumio01 volumio[23098]: ---------------------------- MPD announces state update: player Jan 28 21:03:05 volumio01 volumio[23098]: info: ------------------------------ 176ms Jan 28 21:03:05 volumio01 volumio[23098]: info: sendMpdCommand play took 175 milliseconds Jan 28 21:03:05 volumio01 volumio[23098]: info: ControllerMpd::getState Jan 28 21:03:05 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand status Jan 28 21:03:05 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:05 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:05 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:05 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:05 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:05 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:05 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:05 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:05 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:05 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:05 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:05 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:05 volumio01 volumio[23098]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jan 28 21:03:05 volumio01 volumio[23098]: info: FusionDsp - ---- read samplerate from file: 44100 Jan 28 21:03:05 volumio01 volumio[23098]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jan 28 21:03:05 volumio01 volumio[23098]: info: Jan 28 21:03:05 volumio01 volumio[23098]: ---------------------------- MPD announces state update: player Jan 28 21:03:05 volumio01 volumio[23098]: info: ControllerMpd::getState Jan 28 21:03:05 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand status Jan 28 21:03:05 volumio01 volumio[23098]: info: sendMpdCommand status took 457 milliseconds Jan 28 21:03:05 volumio01 volumio[23098]: verbose: ControllerMpd::parseState Jan 28 21:03:05 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 21:03:05 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:05 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:05 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:05 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:05 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:05 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:05 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:05 volumio01 volumio[23098]: info: sendMpdCommand status took 220 milliseconds Jan 28 21:03:05 volumio01 volumio[23098]: info: sendMpdCommand playlistinfo took 220 milliseconds Jan 28 21:03:05 volumio01 volumio[23098]: verbose: ControllerMpd::parseState Jan 28 21:03:05 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 21:03:05 volumio01 volumio[23098]: verbose: ControllerMpd::parseTrackInfo Jan 28 21:03:05 volumio01 volumio[23098]: info: ControllerMpd::pushState Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::servicePushState Jan 28 21:03:05 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:05 volumio01 volumio[23098]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1329,"duration":60,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"PinkNoise_44k_R","artist":"FusionDsp","album":"Test Signal","uri":"INTERNAL/FusionDsp/tools/PinkNoise_44k_R.wav","trackType":"wav"} Jan 28 21:03:05 volumio01 volumio[23098]: verbose: CURRENT POSITION 6 Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreStateMachine::syncState stateService play Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreStateMachine::syncState currentStatus stop Jan 28 21:03:05 volumio01 volumio[23098]: info: ------------------------------ 687ms Jan 28 21:03:05 volumio01 volumio[23098]: info: sendMpdCommand playlistinfo took 67 milliseconds Jan 28 21:03:05 volumio01 volumio[23098]: verbose: ControllerMpd::parseTrackInfo Jan 28 21:03:05 volumio01 volumio[23098]: info: ControllerMpd::pushState Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::servicePushState Jan 28 21:03:05 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:05 volumio01 volumio[23098]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2223,"duration":60,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"PinkNoise_44k_R","artist":"FusionDsp","album":"Test Signal","uri":"INTERNAL/FusionDsp/tools/PinkNoise_44k_R.wav","trackType":"wav"} Jan 28 21:03:05 volumio01 volumio[23098]: verbose: CURRENT POSITION 6 Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreStateMachine::syncState stateService play Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreStateMachine::syncState currentStatus play Jan 28 21:03:05 volumio01 volumio[23098]: info: Received an update from plugin. extracting info from payload Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreStateMachine::pushState Jan 28 21:03:05 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushState Jan 28 21:03:05 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output update for this device Jan 28 21:03:05 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:05 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreStateMachine::pushState Jan 28 21:03:05 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushState Jan 28 21:03:05 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output update for this device Jan 28 21:03:05 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output Jan 28 21:03:05 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:05 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:05 volumio01 volumio[23098]: info: ------------------------------ 326ms Jan 28 21:03:06 volumio01 volumio[23098]: info: searchQOBUZUri took 1014 milliseconds Jan 28 21:03:06 volumio01 volumio[23098]: info: searchTIDALUri took 1016 milliseconds Jan 28 21:03:06 volumio01 volumio[23098]: info: search took 1017 milliseconds Jan 28 21:03:06 volumio01 volumio[23098]: info: searchQOBUZUri took 1001 milliseconds Jan 28 21:03:06 volumio01 volumio[23098]: info: searchTIDALUri took 1003 milliseconds Jan 28 21:03:06 volumio01 volumio[23098]: info: search took 1005 milliseconds Jan 28 21:03:06 volumio01 volumio[23098]: info: PeppySpectrum ---peppyspectrum status play Jan 28 21:03:06 volumio01 volumio[23098]: info: PeppySpectrum ---peppyspectrum status play Jan 28 21:03:06 volumio01 volumio[23098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Jan 28 21:03:06 volumio01 volumio[23098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Jan 28 21:03:06 volumio01 sudo[8322]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Jan 28 21:03:06 volumio01 sudo[8322]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:06 volumio01 sudo[8324]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Jan 28 21:03:06 volumio01 sudo[8324]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:06 volumio01 systemd[1]: Started peppyspectrum.service - peppyspectrum Daemon. Jan 28 21:03:06 volumio01 sudo[8324]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:06 volumio01 sudo[8322]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:07 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:07 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:07 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:07 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:07 volumio01 volumio[23098]: info: searchQOBUZUri took 2091 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: searchTIDALUri took 2093 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: search took 2096 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:07 volumio01 volumio[23098]: info: searchQOBUZUri took 1914 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: searchTIDALUri took 1920 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: search took 1922 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:07 volumio01 volumio[23098]: info: searchQOBUZUri took 1710 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: searchTIDALUri took 1717 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: search took 1718 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:07 volumio01 volumio[23098]: info: searchQOBUZUri took 1726 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: searchTIDALUri took 1717 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: search took 1721 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: searchQOBUZUri took 2148 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: searchTIDALUri took 2153 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: search took 2154 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:07 volumio01 volumio[23098]: info: searchQOBUZUri took 2152 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: searchQOBUZUri took 2119 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: searchQOBUZUri took 2109 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: searchTIDALUri took 2149 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: search took 2151 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: searchQOBUZUri took 2162 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:07 volumio01 volumio[23098]: info: searchTIDALUri took 2183 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: search took 2185 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:07 volumio01 volumio[23098]: info: searchTIDALUri took 2159 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: search took 2161 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:07 volumio01 volumio[23098]: info: searchTIDALUri took 2124 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: search took 2168 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: searchTIDALUri took 2184 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: search took 2188 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: searchQOBUZUri took 2187 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: searchQOBUZUri took 2157 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: searchQOBUZUri took 2164 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: searchTIDALUri took 2164 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: search took 2166 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: searchTIDALUri took 2194 milliseconds Jan 28 21:03:07 volumio01 volumio[23098]: info: search took 2196 milliseconds Jan 28 21:03:08 volumio01 volumio[23098]: info: peppyspectrum Daemon Started Jan 28 21:03:08 volumio01 volumio[23098]: info: peppyspectrum Daemon Started Jan 28 21:03:08 volumio01 volumio[23098]: info: searchTIDALUri took 2395 milliseconds Jan 28 21:03:08 volumio01 volumio[23098]: info: search took 2396 milliseconds Jan 28 21:03:08 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:08 volumio01 volumio[23098]: info: searchQOBUZUri took 2395 milliseconds Jan 28 21:03:08 volumio01 volumio[23098]: info: searchQOBUZUri took 2390 milliseconds Jan 28 21:03:08 volumio01 volumio[23098]: info: searchTIDALUri took 2390 milliseconds Jan 28 21:03:08 volumio01 volumio[23098]: info: search took 2394 milliseconds Jan 28 21:03:08 volumio01 volumio[23098]: info: searchTIDALUri took 2383 milliseconds Jan 28 21:03:08 volumio01 volumio[23098]: info: search took 2385 milliseconds Jan 28 21:03:08 volumio01 volumio[23098]: info: searchQOBUZUri took 2397 milliseconds Jan 28 21:03:08 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:08 volumio01 volumio[23098]: info: searchTIDALUri took 2390 milliseconds Jan 28 21:03:08 volumio01 volumio[23098]: info: search took 2391 milliseconds Jan 28 21:03:08 volumio01 volumio[23098]: info: searchTIDALUri took 812 milliseconds Jan 28 21:03:08 volumio01 volumio[23098]: info: search took 816 milliseconds Jan 28 21:03:08 volumio01 volumio[23098]: info: searchQOBUZUri took 825 milliseconds Jan 28 21:03:08 volumio01 volumio[23098]: info: searchQOBUZUri took 2410 milliseconds Jan 28 21:03:08 volumio01 volumio[23098]: info: searchTIDALUri took 2401 milliseconds Jan 28 21:03:08 volumio01 volumio[23098]: info: search took 2402 milliseconds Jan 28 21:03:08 volumio01 volumio[23098]: info: searchQOBUZUri took 2458 milliseconds Jan 28 21:03:08 volumio01 systemd[1]: peppyspectrum.service: Deactivated successfully. Jan 28 21:03:08 volumio01 systemd[1]: peppyspectrum.service: Consumed 1.583s CPU time. Jan 28 21:03:15 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:15 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:15 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:15 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:15 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:15 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:15 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:15 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:15 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:15 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:15 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:15 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:15 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:15 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:15 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:15 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:15 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:15 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:15 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:15 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:17 volumio01 volumio[23098]: error: Search in plugin tidal timed out Jan 28 21:03:17 volumio01 volumio[23098]: info: All search sources collected, pushing search results Jan 28 21:03:17 volumio01 volumio[23098]: info: METAVOLUMIO: No new tracks added to queue, Starting fallback strategies Jan 28 21:03:17 volumio01 volumio[23098]: info: METAVOLUMIO: Infinity playback mode stopping, exhausted all strategies to continue Jan 28 21:03:29 volumio01 volumio[23098]: info: Preload queue cleared Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreStateMachine::ClearQueue Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreStateMachine::stop Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreStateMachine::stPlaybackTimer Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreStateMachine::updateTrackBlock Jan 28 21:03:29 volumio01 volumio[23098]: info: CorePlayQueue::getTrackBlock Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreStateMachine::pushState Jan 28 21:03:29 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushState Jan 28 21:03:29 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output update for this device Jan 28 21:03:29 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:29 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreStateMachine::serviceStop Jan 28 21:03:29 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreCommandRouter::serviceStop Jan 28 21:03:29 volumio01 volumio[23098]: info: ControllerMpd::stop Jan 28 21:03:29 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand stop Jan 28 21:03:29 volumio01 volumio[23098]: info: CorePlayQueue::clearPlayQueue Jan 28 21:03:29 volumio01 volumio[23098]: info: CorePlayQueue::saveQueue Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushQueue Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreStateMachine::addQueueItems Jan 28 21:03:29 volumio01 volumio[23098]: info: CorePlayQueue::addQueueItems Jan 28 21:03:29 volumio01 volumio[23098]: info: Preload queue cleared Jan 28 21:03:29 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_L_refL.wav Jan 28 21:03:29 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_L_refL.wav Jan 28 21:03:29 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_LR_refL.wav Jan 28 21:03:29 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_LR_refL.wav Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushQueue Jan 28 21:03:29 volumio01 volumio[23098]: info: CorePlayQueue::saveQueue Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreStateMachine::updateTrackBlock Jan 28 21:03:29 volumio01 volumio[23098]: info: CorePlayQueue::getTrackBlock Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:29 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPlay Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreStateMachine::play index 1 Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreStateMachine::addQueueItems Jan 28 21:03:29 volumio01 volumio[23098]: info: CorePlayQueue::addQueueItems Jan 28 21:03:29 volumio01 volumio[23098]: info: Preload queue cleared Jan 28 21:03:29 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_R_refL.wav Jan 28 21:03:29 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_R_refL.wav Jan 28 21:03:29 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/HouseCurveTestSignal.wav Jan 28 21:03:29 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/HouseCurveTestSignal.wav Jan 28 21:03:29 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_BOTH.wav Jan 28 21:03:29 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_BOTH.wav Jan 28 21:03:29 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_L.wav Jan 28 21:03:29 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_L.wav Jan 28 21:03:29 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_R.wav Jan 28 21:03:29 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_R.wav Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreStateMachine::stop Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushQueue Jan 28 21:03:29 volumio01 volumio[23098]: info: CorePlayQueue::saveQueue Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreStateMachine::play index undefined Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreStateMachine::updateTrackBlock Jan 28 21:03:29 volumio01 volumio[23098]: info: CorePlayQueue::getTrackBlock Jan 28 21:03:29 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:29 volumio01 volumio[23098]: info: CoreStateMachine::startPlaybackTimer Jan 28 21:03:29 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:29 volumio01 volumio[23098]: verbose: ControllerMpd::clearAddPlayTracks INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_LR_refL.wav Jan 28 21:03:29 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand stop Jan 28 21:03:29 volumio01 volumio[23098]: info: PeppySpectrum ---peppyspectrum status stop Jan 28 21:03:29 volumio01 volumio[23098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Jan 28 21:03:29 volumio01 volumio[23098]: info: Jan 28 21:03:29 volumio01 volumio[23098]: ---------------------------- MPD announces state update: player Jan 28 21:03:29 volumio01 volumio[23098]: info: sendMpdCommand stop took 56 milliseconds Jan 28 21:03:29 volumio01 volumio[23098]: info: ControllerMpd::getState Jan 28 21:03:29 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand status Jan 28 21:03:29 volumio01 volumio[23098]: info: sendMpdCommand stop took 36 milliseconds Jan 28 21:03:29 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand clear Jan 28 21:03:29 volumio01 volumio[23098]: info: Jan 28 21:03:29 volumio01 volumio[23098]: ---------------------------- MPD announces system playlist update Jan 28 21:03:29 volumio01 volumio[23098]: info: Ignoring MPD Status Update Jan 28 21:03:29 volumio01 volumio[23098]: info: sendMpdCommand status took 3 milliseconds Jan 28 21:03:29 volumio01 volumio[23098]: info: sendMpdCommand clear took 2 milliseconds Jan 28 21:03:29 volumio01 volumio[23098]: verbose: ControllerMpd::parseState Jan 28 21:03:29 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 21:03:29 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand add "INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_LR_refL.wav" Jan 28 21:03:30 volumio01 sudo[8417]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Jan 28 21:03:30 volumio01 sudo[8417]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:30 volumio01 volumio[23098]: error: updateQueue error: null Jan 28 21:03:30 volumio01 volumio[23098]: info: Jan 28 21:03:30 volumio01 volumio[23098]: ---------------------------- MPD announces system playlist update Jan 28 21:03:30 volumio01 volumio[23098]: info: Ignoring MPD Status Update Jan 28 21:03:30 volumio01 volumio[23098]: info: ------------------------------ 44ms Jan 28 21:03:30 volumio01 volumio[23098]: info: sendMpdCommand playlistinfo took 42 milliseconds Jan 28 21:03:30 volumio01 volumio[23098]: info: sendMpdCommand add "INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_LR_refL.wav" took 43 milliseconds Jan 28 21:03:30 volumio01 volumio[23098]: verbose: ControllerMpd::parseTrackInfo Jan 28 21:03:30 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand play Jan 28 21:03:30 volumio01 volumio[23098]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Jan 28 21:03:30 volumio01 volumio[23098]: info: ------------------------------ 59ms Jan 28 21:03:30 volumio01 volumio[23098]: info: ------------------------------ 19ms Jan 28 21:03:30 volumio01 volumio[23098]: info: sendMpdCommand play took 4 milliseconds Jan 28 21:03:30 volumio01 volumio[23098]: info: touch_display: Setting screensaver timeout to 120 seconds. Jan 28 21:03:30 volumio01 sudo[8417]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:30 volumio01 volumio[23098]: info: peppyspectrum Daemon Stop Jan 28 21:03:30 volumio01 volumio[23098]: info: Jan 28 21:03:30 volumio01 volumio[23098]: ---------------------------- MPD announces state update: player Jan 28 21:03:30 volumio01 volumio[23098]: info: ControllerMpd::getState Jan 28 21:03:30 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand status Jan 28 21:03:30 volumio01 volumio[23098]: info: FusionDsp - ---- read samplerate, raw: Jan 28 21:03:30 volumio01 volumio[23098]: error: FusionDsp - invalid sample rate Jan 28 21:03:30 volumio01 volumio[23098]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jan 28 21:03:30 volumio01 volumio[23098]: info: FusionDsp - ---- read samplerate from file: 44100 Jan 28 21:03:30 volumio01 volumio[23098]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jan 28 21:03:30 volumio01 volumio[23098]: info: Jan 28 21:03:30 volumio01 volumio[23098]: ---------------------------- MPD announces state update: player Jan 28 21:03:30 volumio01 volumio[23098]: info: sendMpdCommand status took 19 milliseconds Jan 28 21:03:30 volumio01 volumio[23098]: info: ControllerMpd::getState Jan 28 21:03:30 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand status Jan 28 21:03:30 volumio01 volumio[23098]: verbose: ControllerMpd::parseState Jan 28 21:03:30 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 21:03:30 volumio01 volumio[23098]: info: sendMpdCommand status took 6 milliseconds Jan 28 21:03:30 volumio01 volumio[23098]: verbose: ControllerMpd::parseState Jan 28 21:03:30 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 21:03:30 volumio01 volumio[23098]: info: sendMpdCommand playlistinfo took 4 milliseconds Jan 28 21:03:30 volumio01 volumio[23098]: info: sendMpdCommand playlistinfo took 1 milliseconds Jan 28 21:03:30 volumio01 volumio[23098]: verbose: ControllerMpd::parseTrackInfo Jan 28 21:03:30 volumio01 volumio[23098]: verbose: ControllerMpd::parseTrackInfo Jan 28 21:03:30 volumio01 volumio[23098]: info: ControllerMpd::pushState Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreCommandRouter::servicePushState Jan 28 21:03:30 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:30 volumio01 volumio[23098]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":16,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"512kMeasSweep_30_to_20k_44k_PCM16_LR_refL","artist":"FusionDsp","album":"Test Signal","uri":"INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_LR_refL.wav","trackType":"wav"} Jan 28 21:03:30 volumio01 volumio[23098]: verbose: CURRENT POSITION 1 Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::syncState stateService play Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::syncState currentStatus stop Jan 28 21:03:30 volumio01 volumio[23098]: info: ControllerMpd::pushState Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreCommandRouter::servicePushState Jan 28 21:03:30 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:30 volumio01 volumio[23098]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1192,"duration":16,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"512kMeasSweep_30_to_20k_44k_PCM16_LR_refL","artist":"FusionDsp","album":"Test Signal","uri":"INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_LR_refL.wav","trackType":"wav"} Jan 28 21:03:30 volumio01 volumio[23098]: verbose: CURRENT POSITION 1 Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::syncState stateService play Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::syncState currentStatus play Jan 28 21:03:30 volumio01 volumio[23098]: info: Received an update from plugin. extracting info from payload Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::pushState Jan 28 21:03:30 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushState Jan 28 21:03:30 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output update for this device Jan 28 21:03:30 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:30 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::pushState Jan 28 21:03:30 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushState Jan 28 21:03:30 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output update for this device Jan 28 21:03:30 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:30 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:30 volumio01 volumio[23098]: info: ------------------------------ 69ms Jan 28 21:03:30 volumio01 volumio[23098]: info: ------------------------------ 71ms Jan 28 21:03:30 volumio01 volumio[23098]: info: PeppySpectrum ---peppyspectrum status play Jan 28 21:03:30 volumio01 volumio[23098]: info: PeppySpectrum ---peppyspectrum status play Jan 28 21:03:30 volumio01 sudo[8423]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Jan 28 21:03:30 volumio01 sudo[8423]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:30 volumio01 volumio[23098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Jan 28 21:03:30 volumio01 volumio[23098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Jan 28 21:03:30 volumio01 sudo[8426]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Jan 28 21:03:30 volumio01 sudo[8426]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:30 volumio01 volumio[23098]: info: Preload queue cleared Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::ClearQueue Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::stop Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::stPlaybackTimer Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::updateTrackBlock Jan 28 21:03:30 volumio01 volumio[23098]: info: CorePlayQueue::getTrackBlock Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::pushState Jan 28 21:03:30 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushState Jan 28 21:03:30 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output update for this device Jan 28 21:03:30 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:30 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::serviceStop Jan 28 21:03:30 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreCommandRouter::serviceStop Jan 28 21:03:30 volumio01 volumio[23098]: info: ControllerMpd::stop Jan 28 21:03:30 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand stop Jan 28 21:03:30 volumio01 volumio[23098]: info: CorePlayQueue::clearPlayQueue Jan 28 21:03:30 volumio01 volumio[23098]: info: CorePlayQueue::saveQueue Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushQueue Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::addQueueItems Jan 28 21:03:30 volumio01 volumio[23098]: info: CorePlayQueue::addQueueItems Jan 28 21:03:30 volumio01 volumio[23098]: info: Preload queue cleared Jan 28 21:03:30 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_L_refL.wav Jan 28 21:03:30 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_L_refL.wav Jan 28 21:03:30 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_LR_refL.wav Jan 28 21:03:30 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_LR_refL.wav Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushQueue Jan 28 21:03:30 volumio01 volumio[23098]: info: CorePlayQueue::saveQueue Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::updateTrackBlock Jan 28 21:03:30 volumio01 volumio[23098]: info: CorePlayQueue::getTrackBlock Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:30 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPlay Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::play index 1 Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::addQueueItems Jan 28 21:03:30 volumio01 volumio[23098]: info: CorePlayQueue::addQueueItems Jan 28 21:03:30 volumio01 volumio[23098]: info: Preload queue cleared Jan 28 21:03:30 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_R_refL.wav Jan 28 21:03:30 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_R_refL.wav Jan 28 21:03:30 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/HouseCurveTestSignal.wav Jan 28 21:03:30 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/HouseCurveTestSignal.wav Jan 28 21:03:30 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_BOTH.wav Jan 28 21:03:30 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_BOTH.wav Jan 28 21:03:30 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_L.wav Jan 28 21:03:30 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_L.wav Jan 28 21:03:30 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_R.wav Jan 28 21:03:30 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_R.wav Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::stop Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushQueue Jan 28 21:03:30 volumio01 volumio[23098]: info: CorePlayQueue::saveQueue Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::play index undefined Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::updateTrackBlock Jan 28 21:03:30 volumio01 volumio[23098]: info: CorePlayQueue::getTrackBlock Jan 28 21:03:30 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::startPlaybackTimer Jan 28 21:03:30 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:30 volumio01 volumio[23098]: verbose: ControllerMpd::clearAddPlayTracks INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_LR_refL.wav Jan 28 21:03:30 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand stop Jan 28 21:03:30 volumio01 volumio[23098]: info: PeppySpectrum ---peppyspectrum status stop Jan 28 21:03:30 volumio01 systemd[1]: Started peppyspectrum.service - peppyspectrum Daemon. Jan 28 21:03:30 volumio01 volumio[23098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Jan 28 21:03:30 volumio01 volumio[23098]: info: Jan 28 21:03:30 volumio01 volumio[23098]: ---------------------------- MPD announces state update: player Jan 28 21:03:30 volumio01 volumio[23098]: info: sendMpdCommand stop took 152 milliseconds Jan 28 21:03:30 volumio01 volumio[23098]: info: ControllerMpd::getState Jan 28 21:03:30 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand status Jan 28 21:03:30 volumio01 volumio[23098]: info: sendMpdCommand stop took 101 milliseconds Jan 28 21:03:30 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand clear Jan 28 21:03:30 volumio01 sudo[8423]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:30 volumio01 sudo[8426]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:30 volumio01 sudo[8431]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Jan 28 21:03:30 volumio01 sudo[8431]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:30 volumio01 volumio[23098]: info: Jan 28 21:03:30 volumio01 volumio[23098]: ---------------------------- MPD announces system playlist update Jan 28 21:03:30 volumio01 volumio[23098]: info: Ignoring MPD Status Update Jan 28 21:03:30 volumio01 volumio[23098]: info: sendMpdCommand status took 87 milliseconds Jan 28 21:03:30 volumio01 volumio[23098]: info: sendMpdCommand clear took 88 milliseconds Jan 28 21:03:30 volumio01 volumio[23098]: verbose: ControllerMpd::parseState Jan 28 21:03:30 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 21:03:30 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand add "INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_LR_refL.wav" Jan 28 21:03:30 volumio01 volumio[23098]: info: peppyspectrum Daemon Started Jan 28 21:03:30 volumio01 volumio[23098]: info: peppyspectrum Daemon Started Jan 28 21:03:30 volumio01 volumio[23098]: error: updateQueue error: null Jan 28 21:03:30 volumio01 volumio[23098]: info: Jan 28 21:03:30 volumio01 volumio[23098]: ---------------------------- MPD announces system playlist update Jan 28 21:03:30 volumio01 volumio[23098]: info: Ignoring MPD Status Update Jan 28 21:03:30 volumio01 volumio[23098]: info: ------------------------------ 32ms Jan 28 21:03:30 volumio01 volumio[23098]: info: sendMpdCommand playlistinfo took 12 milliseconds Jan 28 21:03:30 volumio01 volumio[23098]: info: sendMpdCommand add "INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_LR_refL.wav" took 12 milliseconds Jan 28 21:03:30 volumio01 volumio[23098]: verbose: ControllerMpd::parseTrackInfo Jan 28 21:03:30 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand play Jan 28 21:03:30 volumio01 volumio[23098]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Jan 28 21:03:30 volumio01 volumio[23098]: info: ------------------------------ 137ms Jan 28 21:03:30 volumio01 volumio[23098]: info: touch_display: Setting screensaver timeout to 120 seconds. Jan 28 21:03:30 volumio01 volumio[23098]: info: ------------------------------ 50ms Jan 28 21:03:30 volumio01 volumio[23098]: info: sendMpdCommand play took 47 milliseconds Jan 28 21:03:30 volumio01 systemd[1]: Stopping peppyspectrum.service - peppyspectrum Daemon... Jan 28 21:03:30 volumio01 systemd[1]: peppyspectrum.service: Deactivated successfully. Jan 28 21:03:30 volumio01 systemd[1]: Stopped peppyspectrum.service - peppyspectrum Daemon. Jan 28 21:03:30 volumio01 sudo[8431]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:30 volumio01 volumio[23098]: info: peppyspectrum Daemon Stop Jan 28 21:03:30 volumio01 volumio[23098]: info: Jan 28 21:03:30 volumio01 volumio[23098]: ---------------------------- MPD announces state update: player Jan 28 21:03:30 volumio01 volumio[23098]: info: ControllerMpd::getState Jan 28 21:03:30 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand status Jan 28 21:03:30 volumio01 volumio[23098]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jan 28 21:03:30 volumio01 volumio[23098]: info: FusionDsp - ---- read samplerate from file: 44100 Jan 28 21:03:30 volumio01 volumio[23098]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jan 28 21:03:30 volumio01 volumio[23098]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jan 28 21:03:30 volumio01 volumio[23098]: info: FusionDsp - ---- read samplerate from file: 44100 Jan 28 21:03:30 volumio01 volumio[23098]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jan 28 21:03:30 volumio01 volumio[23098]: info: Jan 28 21:03:30 volumio01 volumio[23098]: ---------------------------- MPD announces state update: player Jan 28 21:03:30 volumio01 volumio[23098]: info: sendMpdCommand status took 18 milliseconds Jan 28 21:03:30 volumio01 volumio[23098]: info: ControllerMpd::getState Jan 28 21:03:30 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand status Jan 28 21:03:30 volumio01 volumio[23098]: verbose: ControllerMpd::parseState Jan 28 21:03:30 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 21:03:30 volumio01 volumio[23098]: info: sendMpdCommand status took 1 milliseconds Jan 28 21:03:30 volumio01 volumio[23098]: info: sendMpdCommand playlistinfo took 2 milliseconds Jan 28 21:03:30 volumio01 volumio[23098]: verbose: ControllerMpd::parseState Jan 28 21:03:30 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 21:03:30 volumio01 volumio[23098]: verbose: ControllerMpd::parseTrackInfo Jan 28 21:03:30 volumio01 volumio[23098]: info: ControllerMpd::pushState Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreCommandRouter::servicePushState Jan 28 21:03:30 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:30 volumio01 volumio[23098]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":16,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"512kMeasSweep_30_to_20k_44k_PCM16_LR_refL","artist":"FusionDsp","album":"Test Signal","uri":"INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_LR_refL.wav","trackType":"wav"} Jan 28 21:03:30 volumio01 volumio[23098]: verbose: CURRENT POSITION 1 Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::syncState stateService play Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::syncState currentStatus stop Jan 28 21:03:30 volumio01 volumio[23098]: info: ------------------------------ 28ms Jan 28 21:03:30 volumio01 volumio[23098]: info: sendMpdCommand playlistinfo took 4 milliseconds Jan 28 21:03:30 volumio01 volumio[23098]: verbose: ControllerMpd::parseTrackInfo Jan 28 21:03:30 volumio01 volumio[23098]: info: ControllerMpd::pushState Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreCommandRouter::servicePushState Jan 28 21:03:30 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:30 volumio01 volumio[23098]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1214,"duration":16,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"512kMeasSweep_30_to_20k_44k_PCM16_LR_refL","artist":"FusionDsp","album":"Test Signal","uri":"INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_LR_refL.wav","trackType":"wav"} Jan 28 21:03:30 volumio01 volumio[23098]: verbose: CURRENT POSITION 1 Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::syncState stateService play Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::syncState currentStatus play Jan 28 21:03:30 volumio01 volumio[23098]: info: Received an update from plugin. extracting info from payload Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreStateMachine::pushState Jan 28 21:03:30 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 21:03:30 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushState Jan 28 21:03:31 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output update for this device Jan 28 21:03:31 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output Jan 28 21:03:31 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:31 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:31 volumio01 volumio[23098]: info: CoreStateMachine::pushState Jan 28 21:03:31 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:31 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushState Jan 28 21:03:31 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output update for this device Jan 28 21:03:31 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output Jan 28 21:03:31 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:31 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:31 volumio01 volumio[23098]: info: ------------------------------ 75ms Jan 28 21:03:31 volumio01 volumio[23098]: info: PeppySpectrum ---peppyspectrum status play Jan 28 21:03:31 volumio01 volumio[23098]: info: PeppySpectrum ---peppyspectrum status play Jan 28 21:03:31 volumio01 volumio[23098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Jan 28 21:03:31 volumio01 volumio[23098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Jan 28 21:03:31 volumio01 sudo[8439]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Jan 28 21:03:31 volumio01 sudo[8439]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:31 volumio01 sudo[8441]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Jan 28 21:03:31 volumio01 sudo[8441]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:31 volumio01 systemd[1]: Started peppyspectrum.service - peppyspectrum Daemon. Jan 28 21:03:31 volumio01 sudo[8441]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:31 volumio01 sudo[8439]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:31 volumio01 volumio[23098]: info: peppyspectrum Daemon Started Jan 28 21:03:31 volumio01 volumio[23098]: info: peppyspectrum Daemon Started Jan 28 21:03:32 volumio01 systemd[1]: peppyspectrum.service: Deactivated successfully. Jan 28 21:03:32 volumio01 systemd[1]: peppyspectrum.service: Consumed 1.413s CPU time. Jan 28 21:03:38 volumio01 volumio[23098]: info: Preload queue cleared Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreStateMachine::ClearQueue Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreStateMachine::stop Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreStateMachine::stPlaybackTimer Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreStateMachine::updateTrackBlock Jan 28 21:03:38 volumio01 volumio[23098]: info: CorePlayQueue::getTrackBlock Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreStateMachine::pushState Jan 28 21:03:38 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushState Jan 28 21:03:38 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output update for this device Jan 28 21:03:38 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:38 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreStateMachine::serviceStop Jan 28 21:03:38 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreCommandRouter::serviceStop Jan 28 21:03:38 volumio01 volumio[23098]: info: ControllerMpd::stop Jan 28 21:03:38 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand stop Jan 28 21:03:38 volumio01 volumio[23098]: info: CorePlayQueue::clearPlayQueue Jan 28 21:03:38 volumio01 volumio[23098]: info: CorePlayQueue::saveQueue Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushQueue Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreStateMachine::addQueueItems Jan 28 21:03:38 volumio01 volumio[23098]: info: CorePlayQueue::addQueueItems Jan 28 21:03:38 volumio01 volumio[23098]: info: Preload queue cleared Jan 28 21:03:38 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_L_refL.wav Jan 28 21:03:38 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_L_refL.wav Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushQueue Jan 28 21:03:38 volumio01 volumio[23098]: info: CorePlayQueue::saveQueue Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreStateMachine::updateTrackBlock Jan 28 21:03:38 volumio01 volumio[23098]: info: CorePlayQueue::getTrackBlock Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:38 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 1 Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPlay Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreStateMachine::play index 0 Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreStateMachine::addQueueItems Jan 28 21:03:38 volumio01 volumio[23098]: info: CorePlayQueue::addQueueItems Jan 28 21:03:38 volumio01 volumio[23098]: info: Preload queue cleared Jan 28 21:03:38 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_LR_refL.wav Jan 28 21:03:38 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_LR_refL.wav Jan 28 21:03:38 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_R_refL.wav Jan 28 21:03:38 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_R_refL.wav Jan 28 21:03:38 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/HouseCurveTestSignal.wav Jan 28 21:03:38 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/HouseCurveTestSignal.wav Jan 28 21:03:38 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_BOTH.wav Jan 28 21:03:38 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_BOTH.wav Jan 28 21:03:38 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_L.wav Jan 28 21:03:38 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_L.wav Jan 28 21:03:38 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_R.wav Jan 28 21:03:38 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_R.wav Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreStateMachine::stop Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushQueue Jan 28 21:03:38 volumio01 volumio[23098]: info: CorePlayQueue::saveQueue Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreStateMachine::play index undefined Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreStateMachine::updateTrackBlock Jan 28 21:03:38 volumio01 volumio[23098]: info: CorePlayQueue::getTrackBlock Jan 28 21:03:38 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 0 Jan 28 21:03:38 volumio01 volumio[23098]: info: CoreStateMachine::startPlaybackTimer Jan 28 21:03:38 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 0 Jan 28 21:03:38 volumio01 volumio[23098]: verbose: ControllerMpd::clearAddPlayTracks INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_L_refL.wav Jan 28 21:03:38 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand stop Jan 28 21:03:38 volumio01 volumio[23098]: info: PeppySpectrum ---peppyspectrum status stop Jan 28 21:03:38 volumio01 volumio[23098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Jan 28 21:03:39 volumio01 volumio[23098]: info: Jan 28 21:03:39 volumio01 volumio[23098]: ---------------------------- MPD announces state update: player Jan 28 21:03:39 volumio01 volumio[23098]: info: sendMpdCommand stop took 109 milliseconds Jan 28 21:03:39 volumio01 volumio[23098]: info: ControllerMpd::getState Jan 28 21:03:39 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand status Jan 28 21:03:39 volumio01 volumio[23098]: info: sendMpdCommand stop took 66 milliseconds Jan 28 21:03:39 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand clear Jan 28 21:03:39 volumio01 volumio[23098]: info: Jan 28 21:03:39 volumio01 volumio[23098]: ---------------------------- MPD announces system playlist update Jan 28 21:03:39 volumio01 volumio[23098]: info: Ignoring MPD Status Update Jan 28 21:03:39 volumio01 volumio[23098]: info: sendMpdCommand status took 5 milliseconds Jan 28 21:03:39 volumio01 volumio[23098]: info: sendMpdCommand clear took 5 milliseconds Jan 28 21:03:39 volumio01 volumio[23098]: verbose: ControllerMpd::parseState Jan 28 21:03:39 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 21:03:39 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand add "INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_L_refL.wav" Jan 28 21:03:39 volumio01 volumio[23098]: error: updateQueue error: null Jan 28 21:03:39 volumio01 volumio[23098]: info: Jan 28 21:03:39 volumio01 volumio[23098]: ---------------------------- MPD announces system playlist update Jan 28 21:03:39 volumio01 volumio[23098]: info: Ignoring MPD Status Update Jan 28 21:03:39 volumio01 volumio[23098]: info: ------------------------------ 54ms Jan 28 21:03:39 volumio01 volumio[23098]: info: sendMpdCommand playlistinfo took 54 milliseconds Jan 28 21:03:39 volumio01 volumio[23098]: info: sendMpdCommand add "INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_L_refL.wav" took 54 milliseconds Jan 28 21:03:39 volumio01 volumio[23098]: verbose: ControllerMpd::parseTrackInfo Jan 28 21:03:39 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand play Jan 28 21:03:39 volumio01 volumio[23098]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Jan 28 21:03:39 volumio01 volumio[23098]: info: ------------------------------ 64ms Jan 28 21:03:39 volumio01 sudo[8487]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Jan 28 21:03:39 volumio01 sudo[8487]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:39 volumio01 volumio[23098]: info: ------------------------------ 19ms Jan 28 21:03:39 volumio01 volumio[23098]: info: sendMpdCommand play took 16 milliseconds Jan 28 21:03:39 volumio01 volumio[23098]: info: touch_display: Setting screensaver timeout to 120 seconds. Jan 28 21:03:39 volumio01 volumio[23098]: info: Jan 28 21:03:39 volumio01 volumio[23098]: ---------------------------- MPD announces state update: player Jan 28 21:03:39 volumio01 volumio[23098]: info: ControllerMpd::getState Jan 28 21:03:39 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand status Jan 28 21:03:39 volumio01 volumio[23098]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jan 28 21:03:39 volumio01 volumio[23098]: info: FusionDsp - ---- read samplerate from file: 44100 Jan 28 21:03:39 volumio01 volumio[23098]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jan 28 21:03:39 volumio01 volumio[23098]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jan 28 21:03:39 volumio01 volumio[23098]: info: FusionDsp - ---- read samplerate from file: 44100 Jan 28 21:03:39 volumio01 volumio[23098]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jan 28 21:03:39 volumio01 volumio[23098]: info: Jan 28 21:03:39 volumio01 volumio[23098]: ---------------------------- MPD announces state update: player Jan 28 21:03:39 volumio01 volumio[23098]: info: sendMpdCommand status took 38 milliseconds Jan 28 21:03:39 volumio01 volumio[23098]: info: ControllerMpd::getState Jan 28 21:03:39 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand status Jan 28 21:03:39 volumio01 volumio[23098]: verbose: ControllerMpd::parseState Jan 28 21:03:39 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 21:03:39 volumio01 sudo[8487]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:39 volumio01 volumio[23098]: info: sendMpdCommand status took 28 milliseconds Jan 28 21:03:39 volumio01 volumio[23098]: info: sendMpdCommand playlistinfo took 29 milliseconds Jan 28 21:03:39 volumio01 volumio[23098]: verbose: ControllerMpd::parseState Jan 28 21:03:39 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 21:03:39 volumio01 volumio[23098]: verbose: ControllerMpd::parseTrackInfo Jan 28 21:03:39 volumio01 volumio[23098]: info: ControllerMpd::pushState Jan 28 21:03:39 volumio01 volumio[23098]: info: CoreCommandRouter::servicePushState Jan 28 21:03:39 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 0 Jan 28 21:03:39 volumio01 volumio[23098]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":13,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"512kMeasSweep_30_to_20k_44k_PCM16_L_refL","artist":"FusionDsp","album":"Test Signal","uri":"INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_L_refL.wav","trackType":"wav"} Jan 28 21:03:39 volumio01 volumio[23098]: verbose: CURRENT POSITION 0 Jan 28 21:03:39 volumio01 volumio[23098]: info: CoreStateMachine::syncState stateService play Jan 28 21:03:39 volumio01 volumio[23098]: info: CoreStateMachine::syncState currentStatus stop Jan 28 21:03:39 volumio01 volumio[23098]: info: ------------------------------ 78ms Jan 28 21:03:39 volumio01 volumio[23098]: info: peppyspectrum Daemon Stop Jan 28 21:03:39 volumio01 volumio[23098]: info: sendMpdCommand playlistinfo took 20 milliseconds Jan 28 21:03:39 volumio01 volumio[23098]: verbose: ControllerMpd::parseTrackInfo Jan 28 21:03:39 volumio01 volumio[23098]: info: ControllerMpd::pushState Jan 28 21:03:39 volumio01 volumio[23098]: info: CoreCommandRouter::servicePushState Jan 28 21:03:39 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 0 Jan 28 21:03:39 volumio01 volumio[23098]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1214,"duration":13,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"512kMeasSweep_30_to_20k_44k_PCM16_L_refL","artist":"FusionDsp","album":"Test Signal","uri":"INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_L_refL.wav","trackType":"wav"} Jan 28 21:03:39 volumio01 volumio[23098]: verbose: CURRENT POSITION 0 Jan 28 21:03:39 volumio01 volumio[23098]: info: CoreStateMachine::syncState stateService play Jan 28 21:03:39 volumio01 volumio[23098]: info: CoreStateMachine::syncState currentStatus play Jan 28 21:03:39 volumio01 volumio[23098]: info: Received an update from plugin. extracting info from payload Jan 28 21:03:39 volumio01 volumio[23098]: info: CoreStateMachine::pushState Jan 28 21:03:39 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 0 Jan 28 21:03:39 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 21:03:39 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushState Jan 28 21:03:39 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output update for this device Jan 28 21:03:39 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output Jan 28 21:03:39 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:39 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 0 Jan 28 21:03:39 volumio01 volumio[23098]: info: CoreStateMachine::pushState Jan 28 21:03:39 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 0 Jan 28 21:03:39 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushState Jan 28 21:03:39 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output update for this device Jan 28 21:03:39 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output Jan 28 21:03:39 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:39 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 0 Jan 28 21:03:39 volumio01 volumio[23098]: info: ------------------------------ 96ms Jan 28 21:03:39 volumio01 volumio[23098]: info: PeppySpectrum ---peppyspectrum status play Jan 28 21:03:39 volumio01 volumio[23098]: info: PeppySpectrum ---peppyspectrum status play Jan 28 21:03:39 volumio01 volumio[23098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Jan 28 21:03:39 volumio01 volumio[23098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Jan 28 21:03:39 volumio01 sudo[8495]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Jan 28 21:03:39 volumio01 sudo[8495]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:39 volumio01 sudo[8497]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Jan 28 21:03:39 volumio01 sudo[8497]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:39 volumio01 systemd[1]: Started peppyspectrum.service - peppyspectrum Daemon. Jan 28 21:03:39 volumio01 sudo[8495]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:39 volumio01 volumio[23098]: info: peppyspectrum Daemon Started Jan 28 21:03:39 volumio01 sudo[8497]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:39 volumio01 volumio[23098]: info: peppyspectrum Daemon Started Jan 28 21:03:40 volumio01 volumio[23098]: info: Preload queue cleared Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreStateMachine::ClearQueue Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreStateMachine::stop Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreStateMachine::stPlaybackTimer Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreStateMachine::updateTrackBlock Jan 28 21:03:40 volumio01 volumio[23098]: info: CorePlayQueue::getTrackBlock Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreStateMachine::pushState Jan 28 21:03:40 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 0 Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushState Jan 28 21:03:40 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output update for this device Jan 28 21:03:40 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:40 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 0 Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreStateMachine::serviceStop Jan 28 21:03:40 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 0 Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreCommandRouter::serviceStop Jan 28 21:03:40 volumio01 volumio[23098]: info: ControllerMpd::stop Jan 28 21:03:40 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand stop Jan 28 21:03:40 volumio01 volumio[23098]: info: CorePlayQueue::clearPlayQueue Jan 28 21:03:40 volumio01 volumio[23098]: info: CorePlayQueue::saveQueue Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushQueue Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreStateMachine::addQueueItems Jan 28 21:03:40 volumio01 volumio[23098]: info: CorePlayQueue::addQueueItems Jan 28 21:03:40 volumio01 volumio[23098]: info: Preload queue cleared Jan 28 21:03:40 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_L_refL.wav Jan 28 21:03:40 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_L_refL.wav Jan 28 21:03:40 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_LR_refL.wav Jan 28 21:03:40 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_LR_refL.wav Jan 28 21:03:40 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_R_refL.wav Jan 28 21:03:40 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_R_refL.wav Jan 28 21:03:40 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/HouseCurveTestSignal.wav Jan 28 21:03:40 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/HouseCurveTestSignal.wav Jan 28 21:03:40 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_BOTH.wav Jan 28 21:03:40 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_BOTH.wav Jan 28 21:03:40 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_L.wav Jan 28 21:03:40 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_L.wav Jan 28 21:03:40 volumio01 volumio[23098]: info: Adding Item to queue: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_R.wav Jan 28 21:03:40 volumio01 volumio[23098]: info: Using cached record of: music-library/INTERNAL/FusionDsp/tools/PinkNoise_44k_R.wav Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushQueue Jan 28 21:03:40 volumio01 volumio[23098]: info: CorePlayQueue::saveQueue Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreStateMachine::updateTrackBlock Jan 28 21:03:40 volumio01 volumio[23098]: info: CorePlayQueue::getTrackBlock Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:40 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 0 Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPlay Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreStateMachine::play index 6 Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreStateMachine::stop Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreStateMachine::play index undefined Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 28 21:03:40 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreStateMachine::startPlaybackTimer Jan 28 21:03:40 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetVisibleSources Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 21:03:40 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jan 28 21:03:40 volumio01 volumio[23098]: info: METAVOLUMIO: Retrieving similar tracks from metavolumio Jan 28 21:03:40 volumio01 volumio[23098]: verbose: ControllerMpd::clearAddPlayTracks INTERNAL/FusionDsp/tools/PinkNoise_44k_R.wav Jan 28 21:03:40 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand stop Jan 28 21:03:41 volumio01 systemd[1]: peppyspectrum.service: Deactivated successfully. Jan 28 21:03:41 volumio01 systemd[1]: peppyspectrum.service: Consumed 1.468s CPU time. Jan 28 21:03:41 volumio01 volumio[23098]: info: CoreCommandRouter::volumioSeek Jan 28 21:03:41 volumio01 volumio[23098]: info: CoreStateMachine::seek Jan 28 21:03:41 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:41 volumio01 volumio[23098]: info: TRACKBLOCK {"uri":"mnt/INTERNAL/FusionDsp/tools/PinkNoise_44k_R.wav","service":"mpd","name":"PinkNoise_44k_R","artist":"FusionDsp","album":"Test Signal","type":"track","tracknumber":0,"albumart":"/albumart?cacheid=923&web=FusionDsp/Test%20Signal/extralarge&path=%2FINTERNAL%2FFusionDsp%2Ftools&metadata=false","duration":60,"trackType":"wav"} Jan 28 21:03:41 volumio01 volumio[23098]: info: CoreStateMachine::startPlaybackTimer Jan 28 21:03:41 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:41 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetVisibleSources Jan 28 21:03:41 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 21:03:41 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jan 28 21:03:41 volumio01 volumio[23098]: info: METAVOLUMIO: Retrieving similar tracks from metavolumio Jan 28 21:03:41 volumio01 volumio[23098]: info: ControllerMpd::seek Jan 28 21:03:41 volumio01 volumio[23098]: info: CoreStateMachine::pushState Jan 28 21:03:41 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:41 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 21:03:41 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushState Jan 28 21:03:41 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output update for this device Jan 28 21:03:41 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output Jan 28 21:03:41 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:41 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:41 volumio01 volumio[23098]: info: PeppySpectrum ---peppyspectrum status stop Jan 28 21:03:41 volumio01 volumio[23098]: info: PeppySpectrum ---peppyspectrum status stop Jan 28 21:03:41 volumio01 volumio[23098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Jan 28 21:03:41 volumio01 volumio[23098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Jan 28 21:03:41 volumio01 sudo[8506]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Jan 28 21:03:41 volumio01 sudo[8506]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:41 volumio01 sudo[8508]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Jan 28 21:03:41 volumio01 volumio[23098]: info: Jan 28 21:03:41 volumio01 volumio[23098]: ---------------------------- MPD announces state update: player Jan 28 21:03:41 volumio01 volumio[23098]: error: null Jan 28 21:03:41 volumio01 volumio[23098]: info: Jan 28 21:03:41 volumio01 volumio[23098]: ---------------------------- MPD announces state update: player Jan 28 21:03:41 volumio01 volumio[23098]: info: sendMpdCommand stop took 919 milliseconds Jan 28 21:03:41 volumio01 volumio[23098]: info: ControllerMpd::getState Jan 28 21:03:41 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand status Jan 28 21:03:41 volumio01 volumio[23098]: info: sendMpdCommand stop took 875 milliseconds Jan 28 21:03:41 volumio01 volumio[23098]: info: ControllerMpd::getState Jan 28 21:03:41 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand status Jan 28 21:03:41 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand clear Jan 28 21:03:41 volumio01 sudo[8508]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:41 volumio01 sudo[8506]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:41 volumio01 sudo[8508]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:42 volumio01 volumio[23098]: info: CoreCommandRouter::volumioSeek Jan 28 21:03:42 volumio01 volumio[23098]: info: CoreStateMachine::seek Jan 28 21:03:42 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:42 volumio01 volumio[23098]: info: TRACKBLOCK {"uri":"mnt/INTERNAL/FusionDsp/tools/PinkNoise_44k_R.wav","service":"mpd","name":"PinkNoise_44k_R","artist":"FusionDsp","album":"Test Signal","type":"track","tracknumber":0,"albumart":"/albumart?cacheid=923&web=FusionDsp/Test%20Signal/extralarge&path=%2FINTERNAL%2FFusionDsp%2Ftools&metadata=false","duration":60,"trackType":"wav"} Jan 28 21:03:42 volumio01 volumio[23098]: info: CoreStateMachine::startPlaybackTimer Jan 28 21:03:42 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:42 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetVisibleSources Jan 28 21:03:42 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 21:03:42 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jan 28 21:03:42 volumio01 volumio[23098]: info: METAVOLUMIO: Retrieving similar tracks from metavolumio Jan 28 21:03:42 volumio01 volumio[23098]: info: ControllerMpd::seek Jan 28 21:03:42 volumio01 volumio[23098]: info: CoreStateMachine::pushState Jan 28 21:03:42 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:42 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 21:03:42 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushState Jan 28 21:03:42 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output update for this device Jan 28 21:03:42 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output Jan 28 21:03:42 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:42 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:42 volumio01 volumio[23098]: info: Jan 28 21:03:42 volumio01 volumio[23098]: ---------------------------- MPD announces state update: player Jan 28 21:03:42 volumio01 volumio[23098]: info: Jan 28 21:03:42 volumio01 volumio[23098]: ---------------------------- MPD announces system playlist update Jan 28 21:03:42 volumio01 volumio[23098]: info: Ignoring MPD Status Update Jan 28 21:03:42 volumio01 volumio[23098]: info: Jan 28 21:03:42 volumio01 volumio[23098]: ---------------------------- MPD announces state update: player Jan 28 21:03:42 volumio01 volumio[23098]: error: [2@0] {seek} Bad song index Jan 28 21:03:42 volumio01 volumio[23098]: info: ControllerMpd::getState Jan 28 21:03:42 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand status Jan 28 21:03:42 volumio01 volumio[23098]: info: sendMpdCommand status took 805 milliseconds Jan 28 21:03:42 volumio01 volumio[23098]: info: sendMpdCommand status took 804 milliseconds Jan 28 21:03:42 volumio01 volumio[23098]: info: sendMpdCommand clear took 803 milliseconds Jan 28 21:03:42 volumio01 volumio[23098]: info: ControllerMpd::getState Jan 28 21:03:42 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand status Jan 28 21:03:42 volumio01 volumio[23098]: verbose: ControllerMpd::parseState Jan 28 21:03:42 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 21:03:42 volumio01 volumio[23098]: verbose: ControllerMpd::parseState Jan 28 21:03:42 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 28 21:03:42 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand add "INTERNAL/FusionDsp/tools/PinkNoise_44k_R.wav" Jan 28 21:03:42 volumio01 volumio[23098]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jan 28 21:03:42 volumio01 volumio[23098]: info: FusionDsp - ---- read samplerate from file: 44100 Jan 28 21:03:42 volumio01 volumio[23098]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jan 28 21:03:42 volumio01 volumio[23098]: info: peppyspectrum Daemon Stop Jan 28 21:03:42 volumio01 volumio[23098]: info: peppyspectrum Daemon Stop Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreCommandRouter::volumioSeek Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreStateMachine::seek Jan 28 21:03:43 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:43 volumio01 volumio[23098]: info: TRACKBLOCK {"uri":"mnt/INTERNAL/FusionDsp/tools/PinkNoise_44k_R.wav","service":"mpd","name":"PinkNoise_44k_R","artist":"FusionDsp","album":"Test Signal","type":"track","tracknumber":0,"albumart":"/albumart?cacheid=923&web=FusionDsp/Test%20Signal/extralarge&path=%2FINTERNAL%2FFusionDsp%2Ftools&metadata=false","duration":60,"trackType":"wav"} Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreStateMachine::startPlaybackTimer Jan 28 21:03:43 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetVisibleSources Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jan 28 21:03:43 volumio01 volumio[23098]: info: METAVOLUMIO: Retrieving similar tracks from metavolumio Jan 28 21:03:43 volumio01 volumio[23098]: info: ControllerMpd::seek Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreStateMachine::pushState Jan 28 21:03:43 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushState Jan 28 21:03:43 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output update for this device Jan 28 21:03:43 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:43 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:43 volumio01 volumio[23098]: error: updateQueue error: null Jan 28 21:03:43 volumio01 volumio[23098]: info: Jan 28 21:03:43 volumio01 volumio[23098]: ---------------------------- MPD announces system playlist update Jan 28 21:03:43 volumio01 volumio[23098]: info: Ignoring MPD Status Update Jan 28 21:03:43 volumio01 volumio[23098]: error: null Jan 28 21:03:43 volumio01 volumio[23098]: info: Jan 28 21:03:43 volumio01 volumio[23098]: ---------------------------- MPD announces state update: player Jan 28 21:03:43 volumio01 volumio[23098]: info: sendMpdCommand status took 1024 milliseconds Jan 28 21:03:43 volumio01 volumio[23098]: info: ------------------------------ 1026ms Jan 28 21:03:43 volumio01 volumio[23098]: info: sendMpdCommand status took 1023 milliseconds Jan 28 21:03:43 volumio01 volumio[23098]: info: sendMpdCommand playlistinfo took 1024 milliseconds Jan 28 21:03:43 volumio01 volumio[23098]: info: sendMpdCommand playlistinfo took 1029 milliseconds Jan 28 21:03:43 volumio01 volumio[23098]: info: sendMpdCommand add "INTERNAL/FusionDsp/tools/PinkNoise_44k_R.wav" took 1030 milliseconds Jan 28 21:03:43 volumio01 volumio[23098]: info: ControllerMpd::getState Jan 28 21:03:43 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand status Jan 28 21:03:43 volumio01 volumio[23098]: verbose: ControllerMpd::parseState Jan 28 21:03:43 volumio01 volumio[23098]: verbose: ControllerMpd::parseState Jan 28 21:03:43 volumio01 volumio[23098]: verbose: ControllerMpd::parseTrackInfo Jan 28 21:03:43 volumio01 volumio[23098]: verbose: ControllerMpd::parseTrackInfo Jan 28 21:03:43 volumio01 volumio[23098]: verbose: ControllerMpd::sendMpdCommand play Jan 28 21:03:43 volumio01 volumio[23098]: info: ControllerMpd::pushState Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreCommandRouter::servicePushState Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreStateMachine::pushState Jan 28 21:03:43 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushState Jan 28 21:03:43 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output update for this device Jan 28 21:03:43 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:43 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:43 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:43 volumio01 volumio[23098]: 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} Jan 28 21:03:43 volumio01 volumio[23098]: verbose: CURRENT POSITION 6 Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreStateMachine::syncState stateService stop Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreStateMachine::syncState currentStatus stop Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreStateMachine::pushState Jan 28 21:03:43 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushState Jan 28 21:03:43 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output update for this device Jan 28 21:03:43 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:43 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:43 volumio01 volumio[23098]: info: No code Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreStateMachine::pushState Jan 28 21:03:43 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushState Jan 28 21:03:43 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output update for this device Jan 28 21:03:43 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:43 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:43 volumio01 volumio[23098]: info: ControllerMpd::pushState Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreCommandRouter::servicePushState Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreStateMachine::pushState Jan 28 21:03:43 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushState Jan 28 21:03:43 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output update for this device Jan 28 21:03:43 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:43 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:43 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:43 volumio01 volumio[23098]: 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} Jan 28 21:03:43 volumio01 volumio[23098]: verbose: CURRENT POSITION 6 Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreStateMachine::syncState stateService stop Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreStateMachine::syncState currentStatus stop Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreStateMachine::pushState Jan 28 21:03:43 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushState Jan 28 21:03:43 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output update for this device Jan 28 21:03:43 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:43 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:43 volumio01 volumio[23098]: info: No code Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreStateMachine::pushState Jan 28 21:03:43 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreCommandRouter::volumioPushState Jan 28 21:03:43 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output update for this device Jan 28 21:03:43 volumio01 volumio[23098]: info: MRS: Pushing multiroomSync output Jan 28 21:03:43 volumio01 volumio[23098]: info: CoreCommandRouter::volumioGetState Jan 28 21:03:43 volumio01 volumio[23098]: info: CorePlayQueue::getTrack 6 Jan 28 21:03:43 volumio01 volumio[23098]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Jan 28 21:03:43 volumio01 volumio[23098]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Jan 28 21:03:43 volumio01 volumio[23098]: info: ------------------------------ 1252ms Jan 28 21:03:43 volumio01 volumio[23098]: info: ------------------------------ 1252ms Jan 28 21:03:43 volumio01 volumio[23098]: info: ------------------------------ 2058ms Jan 28 21:03:43 volumio01 volumio[23098]: info: ------------------------------ 2057ms Jan 28 21:03:43 volumio01 volumio[23098]: info: PeppySpectrum ---peppyspectrum status stop Jan 28 21:03:43 volumio01 volumio[23098]: info: PeppySpectrum ---peppyspectrum status stop Jan 28 21:03:43 volumio01 sudo[8527]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Jan 28 21:03:43 volumio01 sudo[8527]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:43 volumio01 volumio[23098]: info: PeppySpectrum ---peppyspectrum status stop Jan 28 21:03:43 volumio01 volumio[23098]: info: PeppySpectrum ---peppyspectrum status stop Jan 28 21:03:43 volumio01 volumio[23098]: info: PeppySpectrum ---peppyspectrum status stop Jan 28 21:03:43 volumio01 volumio[23098]: info: PeppySpectrum ---peppyspectrum status stop Jan 28 21:03:43 volumio01 sudo[8527]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:43 volumio01 sudo[8530]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Jan 28 21:03:43 volumio01 sudo[8530]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:43 volumio01 volumio[23098]: info: PeppySpectrum ---peppyspectrum status stop Jan 28 21:03:43 volumio01 sudo[8532]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Jan 28 21:03:43 volumio01 sudo[8532]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:43 volumio01 sudo[8534]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Jan 28 21:03:43 volumio01 sudo[8538]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Jan 28 21:03:43 volumio01 sudo[8534]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:44 volumio01 volumio[23098]: info: PeppySpectrum ---peppyspectrum status stop Jan 28 21:03:44 volumio01 sudo[8538]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:44 volumio01 sudo[8536]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Jan 28 21:03:44 volumio01 sudo[8536]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:44 volumio01 sudo[8530]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:44 volumio01 volumio[23098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Jan 28 21:03:44 volumio01 volumio[23098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Jan 28 21:03:44 volumio01 volumio[23098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Jan 28 21:03:44 volumio01 volumio[23098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Jan 28 21:03:44 volumio01 volumio[23098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Jan 28 21:03:44 volumio01 volumio[23098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Jan 28 21:03:44 volumio01 volumio[23098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Jan 28 21:03:44 volumio01 volumio[23098]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85 Jan 28 21:03:44 volumio01 sudo[8543]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Jan 28 21:03:44 volumio01 sudo[8543]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:44 volumio01 sudo[8534]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:44 volumio01 sudo[8546]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Jan 28 21:03:44 volumio01 sudo[8546]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:44 volumio01 sudo[8532]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:44 volumio01 sudo[8538]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:44 volumio01 sudo[8536]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:44 volumio01 sudo[8543]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:44 volumio01 sudo[8546]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:44 volumio01 volumio[23098]: info: touch_display: Setting screensaver timeout to 120 seconds. Jan 28 21:03:44 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:44 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:44 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:44 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:44 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:44 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:44 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:44 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:44 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:44 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:44 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:44 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:44 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:44 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:44 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:44 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:44 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:44 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:44 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:44 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:44 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:44 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:44 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:44 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:45 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:45 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:45 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:45 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:45 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:45 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:45 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:45 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:45 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:45 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:45 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:45 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:45 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:45 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:45 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:45 volumio01 volumio[23098]: info: All cached search sources collected Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 28 21:03:45 volumio01 volumio[23098]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 28 21:03:45 volumio01 volumio[23098]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 21:03:45 volumio01 volumio[23098]: Error [ERR_INTERNAL_ASSERTION]: This is caused by either a bug in Node.js or incorrect usage of Node.js internals. Jan 28 21:03:45 volumio01 volumio[23098]: Please open an issue with this stack trace at https://github.com/nodejs/node/issues Jan 28 21:03:45 volumio01 volumio[23098]: at new NodeError (node:internal/errors:405:5) Jan 28 21:03:45 volumio01 volumio[23098]: at assert (node:internal/assert:14:11) Jan 28 21:03:45 volumio01 volumio[23098]: at internalConnectMultiple (node:net:1118:3) Jan 28 21:03:45 volumio01 volumio[23098]: at Timeout.internalConnectMultipleTimeout (node:net:1687:3) Jan 28 21:03:45 volumio01 volumio[23098]: at listOnTimeout (node:internal/timers:575:11) Jan 28 21:03:45 volumio01 volumio[23098]: at process.processTimers (node:internal/timers:514:7) { Jan 28 21:03:45 volumio01 volumio[23098]: code: 'ERR_INTERNAL_ASSERTION' Jan 28 21:03:45 volumio01 volumio[23098]: } Jan 28 21:03:45 volumio01 volumio[23098]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 21:03:46 volumio01 sudo[8564]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 21:02' Jan 28 21:03:46 volumio01 sudo[8564]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:47 volumio01 sudo[8564]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:47 volumio01 qobuz-connect[23750]: 20260128 21:03:47.720 [23750.23750] INFO SampleApp: Socket closed Jan 28 21:03:47 volumio01 vtcs[23801]: [2026-01-28 21:03:47.721] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected Jan 28 21:03:47 volumio01 go-librespot[23511]: time="2026-01-28T21:03:47+01:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Jan 28 21:03:47 volumio01 volumio-remote-updater[784]: [2026-01-28 21:03:47] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 21:03:47 volumio01 volumio-remote-updater[784]: [2026-01-28 21:03:47] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 21:03:47 volumio01 systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 21:03:48 volumio01 systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 21:03:48 volumio01 systemd[1]: volumio.service: Consumed 14min 54.933s CPU time. Jan 28 21:03:48 volumio01 systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 21:03:48 volumio01 systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 21:03:48 volumio01 systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2. Jan 28 21:03:48 volumio01 systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 21:03:48 volumio01 systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 21:03:48 volumio01 systemd[1]: volumio.service: Consumed 14min 54.933s CPU time. Jan 28 21:03:48 volumio01 systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 21:03:48 volumio01 systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 21:03:50 volumio01 volumio[8617]: info: ------------------------------------------- Jan 28 21:03:50 volumio01 volumio[8617]: info: ----- Volumio3 ---- Jan 28 21:03:50 volumio01 volumio[8617]: info: ------------------------------------------- Jan 28 21:03:50 volumio01 volumio[8617]: info: ----- System startup ---- Jan 28 21:03:50 volumio01 volumio[8617]: info: ------------------------------------------- Jan 28 21:03:51 volumio01 volumio[8617]: info: MYVOLUMIO Environment detected Jan 28 21:03:51 volumio01 volumio[8617]: info: Plugin folders cleanup Jan 28 21:03:51 volumio01 volumio[8617]: info: Scanning into folder /volumio/app/plugins/ Jan 28 21:03:51 volumio01 volumio[8617]: info: Scanning category audio_interface Jan 28 21:03:51 volumio01 volumio[8617]: info: Scanning category miscellanea Jan 28 21:03:51 volumio01 volumio[8617]: info: Scanning category music_service Jan 28 21:03:51 volumio01 volumio[8617]: info: Scanning category plugins.json Jan 28 21:03:51 volumio01 volumio[8617]: info: Scanning category system_controller Jan 28 21:03:51 volumio01 volumio[8617]: info: Scanning category user_interface Jan 28 21:03:51 volumio01 volumio[8617]: info: Scanning into folder /data/plugins/ Jan 28 21:03:51 volumio01 volumio[8617]: info: Scanning category audio_interface Jan 28 21:03:51 volumio01 volumio[8617]: info: Scanning category music_service Jan 28 21:03:51 volumio01 volumio[8617]: info: Scanning category system_controller Jan 28 21:03:51 volumio01 volumio[8617]: info: Scanning category system_hardware Jan 28 21:03:51 volumio01 volumio[8617]: info: Scanning category user_interface Jan 28 21:03:51 volumio01 volumio[8617]: info: Plugin folders cleanup completed Jan 28 21:03:51 volumio01 volumio[8617]: info: ------------------------------------------- Jan 28 21:03:51 volumio01 volumio[8617]: info: ----- Core plugins startup ---- Jan 28 21:03:51 volumio01 volumio[8617]: info: ------------------------------------------- Jan 28 21:03:51 volumio01 volumio[8617]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 21:03:51 volumio01 volumio[8617]: info: Adding plugin upnp to MyMusic Plugins Jan 28 21:03:51 volumio01 volumio[8617]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 21:03:51 volumio01 volumio[8617]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 21:03:51 volumio01 volumio[8617]: info: Loading plugins from folder /data/plugins/ Jan 28 21:03:51 volumio01 volumio[8617]: info: Loading plugin "system"... Jan 28 21:03:51 volumio01 volumio[8617]: info: Loading plugin "appearance"... Jan 28 21:03:52 volumio01 volumio-remote-updater[784]: [2026-01-28 21:03:52] [connect] Successful connection Jan 28 21:03:53 volumio01 volumio[8617]: info: Loading plugin "network"... Jan 28 21:03:53 volumio01 volumio[8617]: info: Refreshing Cached IP Addresses Jan 28 21:03:53 volumio01 sudo[8647]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 21:03:53 volumio01 sudo[8647]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:53 volumio01 sudo[8649]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 21:03:53 volumio01 volumio[8617]: info: Loading plugin "services"... Jan 28 21:03:53 volumio01 sudo[8649]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:53 volumio01 volumio[8617]: info: Loading plugin "alsa_controller"... Jan 28 21:03:53 volumio01 sudo[8647]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:53 volumio01 sudo[8649]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:53 volumio01 sudo[8656]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 21:03:53 volumio01 sudo[8656]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:53 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 21:03:53 volumio01 volumio[8617]: info: Loading plugin "wizard"... Jan 28 21:03:53 volumio01 volumio[8617]: info: Loading plugin "networkfs"... Jan 28 21:03:53 volumio01 volumio[8617]: info: Starting Udev Watcher for removable devices Jan 28 21:03:53 volumio01 volumio[8617]: info: Ignoring mount for partition: boot Jan 28 21:03:53 volumio01 volumio[8617]: info: Ignoring mount for partition: volumio Jan 28 21:03:53 volumio01 volumio[8617]: info: Ignoring mount for partition: volumio_data Jan 28 21:03:53 volumio01 volumio[8617]: info: Mounting Device 0130-6627 Jan 28 21:03:53 volumio01 sudo[8683]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/0130-6627 -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Jan 28 21:03:53 volumio01 sudo[8683]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:03:53 volumio01 sudo[8683]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:53 volumio01 volumio[8617]: mount: /media/0130-6627: /dev/sda1 already mounted on /media/0130-6627. Jan 28 21:03:53 volumio01 volumio[8617]: dmesg(1) may have more information after failed mount system call. Jan 28 21:03:53 volumio01 volumio[8617]: error: Failed to mount 0130-6627: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/0130-6627" -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Jan 28 21:03:53 volumio01 volumio[8617]: mount: /media/0130-6627: /dev/sda1 already mounted on /media/0130-6627. Jan 28 21:03:53 volumio01 volumio[8617]: dmesg(1) may have more information after failed mount system call. Jan 28 21:03:53 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 21:03:53 volumio01 volumio[8617]: info: Loading plugin "volumio_command_line_client"... Jan 28 21:03:53 volumio01 volumio[8617]: info: Loading plugin "upnp"... Jan 28 21:03:53 volumio01 volumio[8617]: info: [1769630633747] Starting Upmpd Daemon Jan 28 21:03:53 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 21:03:53 volumio01 volumio[8617]: info: Loading plugin "my_music"... Jan 28 21:03:53 volumio01 volumio[8617]: info: Loading plugin "mpd"... Jan 28 21:03:54 volumio01 volumio[8617]: info: Loading plugin "upnp_browser"... Jan 28 21:03:56 volumio01 volumio[8617]: info: Starting UPNP Browser Jan 28 21:03:56 volumio01 volumio[8617]: info: Loading plugin "alarm-clock"... Jan 28 21:03:56 volumio01 volumio[8617]: info: Loading plugin "airplay_emulation"... Jan 28 21:03:56 volumio01 volumio[8617]: info: Starting Shairport Sync Jan 28 21:03:56 volumio01 volumio[8617]: info: Loading plugin "last_100"... Jan 28 21:03:56 volumio01 volumio[8617]: info: Loading plugin "webradio"... Jan 28 21:03:56 volumio01 volumio[8617]: info: Loading plugin "i2s_dacs"... Jan 28 21:03:56 volumio01 volumio[8617]: info: Loading plugin "volumiodiscovery"... Jan 28 21:03:56 volumio01 volumio[8617]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 21:03:56 volumio01 volumio[8617]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 21:03:56 volumio01 volumio[8617]: *** WARNING *** For more information see Jan 28 21:03:56 volumio01 volumio[8617]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 21:03:56 volumio01 volumio[8617]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 21:03:56 volumio01 volumio[8617]: *** WARNING *** For more information see Jan 28 21:03:56 volumio01 node[8617]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 21:03:56 volumio01 node[8617]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 21:03:56 volumio01 node[8617]: *** WARNING *** For more information see Jan 28 21:03:56 volumio01 node[8617]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 21:03:56 volumio01 node[8617]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 21:03:56 volumio01 node[8617]: *** WARNING *** For more information see Jan 28 21:03:56 volumio01 volumio[8617]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 21:03:56 volumio01 volumio[8617]: info: Discovery: Started advertising with name: Volumio01 Jan 28 21:03:56 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 21:03:56 volumio01 volumio[8617]: info: Loading plugin "spop"... Jan 28 21:03:57 volumio01 sudo[8656]: pam_unix(sudo:session): session closed for user root Jan 28 21:03:57 volumio01 volumio[8617]: info: Loading plugin "ytmusic"... Jan 28 21:03:58 volumio01 volumio[8617]: info: Loading plugin "autostart"... Jan 28 21:03:58 volumio01 volumio[8617]: info: Applying required configuration parameters for plugin autostart Jan 28 21:03:58 volumio01 volumio[8617]: info: AutoStart - onVolumioStart - read config.json Jan 28 21:03:58 volumio01 volumio[8617]: info: Loading plugin "outputs"... Jan 28 21:03:58 volumio01 volumio[8617]: info: Loading plugin "albumart"... Jan 28 21:03:58 volumio01 volumio[8617]: info: Plugin example_plugin is not enabled Jan 28 21:03:58 volumio01 volumio[8617]: info: Loading plugin "inputs"... Jan 28 21:03:58 volumio01 volumio[8617]: info: Loading plugin "updater_comm"... Jan 28 21:03:59 volumio01 volumio[8617]: info: Plugin mpdemulation is not enabled Jan 28 21:03:59 volumio01 volumio[8617]: info: Loading plugin "rest_api"... Jan 28 21:03:59 volumio01 volumio[8617]: info: Loading plugin "websocket"... Jan 28 21:03:59 volumio01 volumio[8617]: info: Starting Socket.io Server version 1.7.4 Jan 28 21:03:59 volumio01 volumio[8617]: info: Loading plugin "fusiondsp"... Jan 28 21:03:59 volumio01 volumio[8617]: info: Applying required configuration parameters for plugin fusiondsp Jan 28 21:03:59 volumio01 volumio[8617]: info: Loading plugin "minidlna"... Jan 28 21:03:59 volumio01 volumio[8687]: Forking 3 albumart workers Jan 28 21:03:59 volumio01 volumio[8617]: info: Applying required configuration parameters for plugin minidlna Jan 28 21:04:00 volumio01 volumio[8617]: info: Loading plugin "rpi_eeprom_config"... Jan 28 21:04:00 volumio01 volumio[8617]: info: Applying required configuration parameters for plugin rpi_eeprom_config Jan 28 21:04:00 volumio01 volumio[8617]: info: [RpiEepromConfig] Hardware capabilities loaded Jan 28 21:04:00 volumio01 volumio[8617]: info: Loading plugin "Bluetoothremote"... Jan 28 21:04:00 volumio01 volumio[8617]: info: Applying required configuration parameters for plugin Bluetoothremote Jan 28 21:04:00 volumio01 volumio[8617]: info: Loading plugin "peppyspectrum"... Jan 28 21:04:01 volumio01 volumio[8617]: info: Loading plugin "touch_display"... Jan 28 21:04:01 volumio01 volumio[8697]: Starting albumart workers Jan 28 21:04:01 volumio01 volumio[8698]: Starting albumart workers Jan 28 21:04:01 volumio01 volumio[8617]: info: Applying required configuration parameters for plugin touch_display Jan 28 21:04:01 volumio01 volumio[8699]: Starting albumart workers Jan 28 21:04:01 volumio01 volumio[8617]: info: Loading i18n strings for locale de Jan 28 21:04:01 volumio01 volumio[8617]: info: Plugin peppyspectrum has duplicated i18n key SPEICHERN. It is ignored. Jan 28 21:04:01 volumio01 volumio[8617]: info: Plugin peppyspectrum has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. Jan 28 21:04:01 volumio01 volumio[8617]: info: Plugin peppyspectrum has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. Jan 28 21:04:01 volumio01 volumio[8617]: Updating browse sources language Jan 28 21:04:01 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 21:04:02 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 21:04:02 volumio01 volumio[8617]: info: CoreCommandRouter::initPlayerControls Jan 28 21:04:02 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:02 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:02 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:02 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:02 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:02 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:02 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:02 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:02 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 21:04:02 volumio01 volumio[8617]: Express server listening on port 3000 Jan 28 21:04:02 volumio01 volumio[8617]: [Metrics] WebUI: 11s 883.22ms Jan 28 21:04:02 volumio01 volumio[8617]: info: CoreStateMachine::resetVolumioState Jan 28 21:04:02 volumio01 volumio[8617]: info: CoreStateMachine::getcurrentVolume Jan 28 21:04:02 volumio01 volumio[8617]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 21:04:02 volumio01 volumio[8617]: info: Volumio Network Manager: Network status updated: 2 Jan 28 21:04:02 volumio01 volumio[8617]: verbose: New Socket.io Connection to 192.168.178.129 from 192.168.178.100 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:147.0) Gecko/20100101 Firefox/147.0 Engine version: 3 Transport: polling Total Clients: 1 Jan 28 21:04:02 volumio01 volumio[8617]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Jan 28 21:04:02 volumio01 volumio[8617]: verbose: New Socket.io Connection to 192.168.178.129 from 192.168.178.100 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:147.0) Gecko/20100101 Firefox/147.0 Engine version: 3 Transport: polling Total Clients: 2 Jan 28 21:04:02 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 21:04:02 volumio01 volumio[8617]: info: Reloading queue from file Jan 28 21:04:02 volumio01 volumio[8617]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Jan 28 21:04:02 volumio01 volumio[8617]: info: VolumeController:: Volume=undefined Mute =false Jan 28 21:04:02 volumio01 volumio[8617]: info: CoreStateMachine::pushState Jan 28 21:04:02 volumio01 volumio[8617]: info: CorePlayQueue::getTrack 0 Jan 28 21:04:02 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 21:04:02 volumio01 volumio[8617]: info: CoreCommandRouter::volumioPushState Jan 28 21:04:02 volumio01 volumio[8617]: info: CoreStateMachine::updateTrackBlock Jan 28 21:04:02 volumio01 volumio[8617]: info: CorePlayQueue::getTrackBlock Jan 28 21:04:02 volumio01 volumio[8617]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 21:04:02 volumio01 volumio[8617]: info: CoreStateMachine::setRepeat true single undefined Jan 28 21:04:02 volumio01 volumio[8617]: info: CoreStateMachine::pushState Jan 28 21:04:02 volumio01 volumio[8617]: info: CorePlayQueue::getTrack 0 Jan 28 21:04:02 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 21:04:02 volumio01 volumio[8617]: info: CoreCommandRouter::volumioPushState Jan 28 21:04:02 volumio01 volumio[8617]: info: CoreStateMachine::setRandom null Jan 28 21:04:02 volumio01 volumio[8617]: info: CoreStateMachine::pushState Jan 28 21:04:02 volumio01 volumio[8617]: info: CorePlayQueue::getTrack 0 Jan 28 21:04:02 volumio01 volumio[8617]: info: CoreCommandRouter::volumioPushState Jan 28 21:04:02 volumio01 volumio[8617]: info: Setting Device type: Raspberry PI Jan 28 21:04:02 volumio01 volumio[8617]: info: Completed loading Core Plugins Jan 28 21:04:02 volumio01 volumio[8617]: info: Preparing to generate the ALSA configuration file Jan 28 21:04:03 volumio01 volumio[8617]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Jan 28 21:04:03 volumio01 volumio[8617]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03114 Jan 28 21:04:03 volumio01 volumio[8617]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Jan 28 21:04:03 volumio01 volumio[8617]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jan 28 21:04:03 volumio01 volumio[8617]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 28 21:04:03 volumio01 volumio[8617]: info: Reading ALSA contributions from plugins. Jan 28 21:04:03 volumio01 volumio[8617]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Jan 28 21:04:03 volumio01 volumio[8617]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Jan 28 21:04:03 volumio01 volumio[8617]: verbose: New Socket.io Connection to 192.168.178.129 from 192.168.178.100 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:147.0) Gecko/20100101 Firefox/147.0 Engine version: 3 Transport: polling Total Clients: 5 Jan 28 21:04:03 volumio01 volumio[8617]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Jan 28 21:04:03 volumio01 volumio[8617]: verbose: New Socket.io Connection to 192.168.178.129 from 192.168.178.100 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:147.0) Gecko/20100101 Firefox/147.0 Engine version: 3 Transport: polling Total Clients: 7 Jan 28 21:04:03 volumio01 volumio[8617]: info: VolumeController:: Volume=undefined Mute =false Jan 28 21:04:03 volumio01 volumio[8617]: info: CoreStateMachine::pushState Jan 28 21:04:03 volumio01 volumio[8617]: info: CorePlayQueue::getTrack 0 Jan 28 21:04:03 volumio01 volumio[8617]: info: CoreCommandRouter::volumioPushState Jan 28 21:04:03 volumio01 volumio[8617]: info: Discovery: adding e7956934-6de7-49f8-9feb-07ae3f7ff5bc Jan 28 21:04:03 volumio01 volumio[8617]: info: Discovery: Found device Volumio01 Jan 28 21:04:03 volumio01 volumio[8617]: info: CoreCommandRouter::volumioGetState Jan 28 21:04:03 volumio01 volumio[8617]: info: CorePlayQueue::getTrack 0 Jan 28 21:04:03 volumio01 volumio[8617]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Jan 28 21:04:03 volumio01 volumio[8617]: info: Discovery: this is already registered, e7956934-6de7-49f8-9feb-07ae3f7ff5bc Jan 28 21:04:03 volumio01 volumio[8617]: info: Discovery: Found device Volumio01 Jan 28 21:04:03 volumio01 volumio[8617]: info: CoreCommandRouter::volumioGetState Jan 28 21:04:03 volumio01 volumio[8617]: info: CorePlayQueue::getTrack 0 Jan 28 21:04:03 volumio01 volumio[8617]: info: Asound.conf file written Jan 28 21:04:03 volumio01 sudo[8763]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Jan 28 21:04:03 volumio01 sudo[8763]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:03 volumio01 sudo[8763]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:03 volumio01 volumio[8617]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Jan 28 21:04:03 volumio01 volumio[8617]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Jan 28 21:04:03 volumio01 volumio[8617]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:7 use case configuration -2 Jan 28 21:04:03 volumio01 volumio[8617]: info: Output device has changed, restarting MPD Jan 28 21:04:03 volumio01 volumio[8617]: info: Output device has changed, restarting Shairport Sync Jan 28 21:04:03 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:03 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 21:04:03 volumio01 sudo[8769]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 21:04:03 volumio01 sudo[8769]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:03 volumio01 sudo[8775]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 21:04:03 volumio01 sudo[8775]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:03 volumio01 sudo[8769]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:03 volumio01 volumio[8617]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 21:04:03 volumio01 volumio[8617]: info: ___________ START PLUGINS ___________ Jan 28 21:04:03 volumio01 volumio[8617]: info: ControllerMpd::onStart: Initializing MPD Jan 28 21:04:03 volumio01 volumio[8617]: info: Creating MPD Configuration file Jan 28 21:04:03 volumio01 systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 21:04:03 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 21:04:03 volumio01 volumio[8617]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 21:04:03 volumio01 volumio[8617]: info: [1769630643638] CoreMusicLibrary::Adding element Medienserver Jan 28 21:04:03 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 21:04:03 volumio01 sudo[8793]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 21:04:03 volumio01 sudo[8793]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:03 volumio01 sudo[8793]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:03 volumio01 volumio[8617]: info: UPNP Browser: Client initialized successfully Jan 28 21:04:03 volumio01 sudo[8795]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 21:04:03 volumio01 sudo[8795]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:03 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:03 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 21:04:03 volumio01 systemd[1]: mpd.service: Deactivated successfully. Jan 28 21:04:03 volumio01 systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 21:04:03 volumio01 systemd[1]: mpd.service: Consumed 1min 40.595s CPU time. Jan 28 21:04:03 volumio01 volumio[8617]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 21:04:03 volumio01 systemd[1]: mpd.socket: Deactivated successfully. Jan 28 21:04:03 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:03 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 21:04:03 volumio01 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 21:04:03 volumio01 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 21:04:03 volumio01 volumio[8617]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 21:04:03 volumio01 volumio[8617]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 21:04:03 volumio01 volumio[8617]: info: [1769630643788] CoreMusicLibrary::Adding element Last_100 Jan 28 21:04:03 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 21:04:03 volumio01 volumio[8617]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 21:04:03 volumio01 volumio[8617]: info: [1769630643796] CoreMusicLibrary::Adding element Webradio Jan 28 21:04:03 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 21:04:03 volumio01 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 21:04:03 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 21:04:03 volumio01 volumio[8617]: info: Initializing BBC Radios Jan 28 21:04:03 volumio01 systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 21:04:03 volumio01 systemd[1]: mpd.service: Deactivated successfully. Jan 28 21:04:03 volumio01 systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 21:04:03 volumio01 systemd[1]: mpd.socket: Deactivated successfully. Jan 28 21:04:03 volumio01 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 21:04:03 volumio01 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 21:04:03 volumio01 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 21:04:03 volumio01 systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 21:04:03 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 21:04:03 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 21:04:03 volumio01 volumio[8617]: info: Creating Spotify config file Jan 28 21:04:03 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:04 volumio01 volumio[8617]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 21:04:04 volumio01 volumio[8617]: info: [1769630644005] CoreMusicLibrary::Adding element YouTube Music Jan 28 21:04:04 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 21:04:04 volumio01 volumio[8617]: Cannot find translation for source YouTube Music Jan 28 21:04:04 volumio01 volumio[8617]: info: AutoStart - onStart - waiting for system ready state Jan 28 21:04:04 volumio01 volumio[8617]: info: AutoStart - Polling config: interval=5000ms, maxAttempts=60 Jan 28 21:04:04 volumio01 volumio[8617]: info: AutoStart - Maximum wait time: 300 seconds Jan 28 21:04:04 volumio01 volumio[8617]: info: AutoStart - Startup volume disabled Jan 28 21:04:04 volumio01 volumio[8617]: info: AutoStart - Check #1/60 - VOLUMIO_SYSTEM_STATUS = starting Jan 28 21:04:04 volumio01 volumio[8617]: info: FusionDsp - CamillaDSP binary found. Jan 28 21:04:04 volumio01 volumio[8617]: info: Loading i18n strings for locale de Jan 28 21:04:04 volumio01 volumio[8617]: info: Plugin peppyspectrum has duplicated i18n key SPEICHERN. It is ignored. Jan 28 21:04:04 volumio01 volumio[8617]: info: Plugin peppyspectrum has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. Jan 28 21:04:04 volumio01 volumio[8617]: info: Plugin peppyspectrum has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. Jan 28 21:04:04 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 28 21:04:04 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:04 volumio01 volumio[8617]: info: FusionDsp - mixtype--------------------- undefined Jan 28 21:04:04 volumio01 volumio[8617]: info: Loading i18n strings for locale de Jan 28 21:04:04 volumio01 volumio[8617]: info: Plugin peppyspectrum has duplicated i18n key SPEICHERN. It is ignored. Jan 28 21:04:04 volumio01 volumio[8617]: info: Plugin peppyspectrum has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. Jan 28 21:04:04 volumio01 volumio[8617]: info: Plugin peppyspectrum has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. Jan 28 21:04:04 volumio01 volumio[8617]: info: [RpiEepromConfig] Starting Raspberry Pi EEPROM Configuration Manager Jan 28 21:04:04 volumio01 volumio[8617]: info: [RpiEepromConfig] Detected full model string: Raspberry Pi 4 Model B Rev 1.4 Jan 28 21:04:04 volumio01 volumio[8617]: info: [RpiEepromConfig] Matched to capability profile: Raspberry Pi 4 Model B Jan 28 21:04:04 volumio01 volumio[8617]: info: [RpiEepromConfig] Detected model: Raspberry Pi 4 Model B Jan 28 21:04:04 volumio01 volumio[8617]: info: [RpiEepromConfig] Boot modes: sd, usb Jan 28 21:04:04 volumio01 volumio[8617]: info: [RpiEepromConfig] Using rpi-eeprom-config at: /usr/bin/rpi-eeprom-config Jan 28 21:04:04 volumio01 volumio[8617]: info: [RpiEepromConfig] Backup directory ensured: /data/configuration/system_controller/rpi_eeprom_config/backup Jan 28 21:04:04 volumio01 volumio[8617]: info: [RpiEepromConfig] Plugin started successfully Jan 28 21:04:04 volumio01 volumio[8617]: info: Loading i18n strings for locale de Jan 28 21:04:04 volumio01 volumio[8617]: info: Plugin peppyspectrum has duplicated i18n key SPEICHERN. It is ignored. Jan 28 21:04:04 volumio01 volumio[8617]: info: Plugin peppyspectrum has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. Jan 28 21:04:04 volumio01 volumio[8617]: info: Plugin peppyspectrum has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. Jan 28 21:04:04 volumio01 sudo[8815]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 21:04:04 volumio01 sudo[8815]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 21:04:04 volumio01 sudo[8815]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:04 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 28 21:04:04 volumio01 volumio[8617]: info: Loading i18n strings for locale de Jan 28 21:04:04 volumio01 volumio[8617]: info: Plugin peppyspectrum has duplicated i18n key SPEICHERN. It is ignored. Jan 28 21:04:04 volumio01 volumio[8617]: info: Plugin peppyspectrum has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. Jan 28 21:04:04 volumio01 volumio[8617]: info: Plugin peppyspectrum has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. Jan 28 21:04:04 volumio01 sudo[8829]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/modprobe snd-aloop index=7 pcm_substreams=1 Jan 28 21:04:04 volumio01 sudo[8829]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:04 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 21:04:04 volumio01 volumio[8617]: info: Volumio Calling Home Jan 28 21:04:04 volumio01 sudo[8829]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:04 volumio01 sudo[8832]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /data/volumiokioskextensions/IframeKeyboardBridge Jan 28 21:04:04 volumio01 sudo[8832]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:04 volumio01 sudo[8832]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:04 volumio01 volumio[8617]: info: Preparing to generate the ALSA configuration file Jan 28 21:04:04 volumio01 sudo[8839]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Jan 28 21:04:04 volumio01 sudo[8839]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:04 volumio01 sudo[8843]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jan 28 21:04:04 volumio01 sudo[8843]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:04 volumio01 sudo[8841]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Jan 28 21:04:04 volumio01 sudo[8841]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:04 volumio01 systemd[1]: Reloading. Jan 28 21:04:04 volumio01 volumio[8617]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jan 28 21:04:04 volumio01 volumio[8617]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 28 21:04:04 volumio01 volumio[8617]: info: Reading ALSA contributions from plugins. Jan 28 21:04:04 volumio01 volumio[8617]: info: touch_display: Backlight interface detected. Jan 28 21:04:04 volumio01 volumio[8617]: error: Upnp client error: Error: This socket has been ended by the other party Jan 28 21:04:04 volumio01 sudo[8855]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 21:04:04 volumio01 sudo[8855]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:04 volumio01 sudo[8855]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:04 volumio01 sudo[8864]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 21:04:04 volumio01 sudo[8864]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:04 volumio01 sudo[8864]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:05 volumio01 volumio[8617]: info: snd_dummy loaded Jan 28 21:04:05 volumio01 volumio[8617]: info: minidlna: Found miniDLNA version 1.3.0 Jan 28 21:04:05 volumio01 volumio[8617]: info: minidlna: Starting minidlna.service Jan 28 21:04:05 volumio01 volumio[8617]: info: MPD Permissions set Jan 28 21:04:05 volumio01 volumio[8617]: info: MPD Permissions set Jan 28 21:04:05 volumio01 sudo[8874]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start minidlna.service Jan 28 21:04:05 volumio01 sudo[8874]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:05 volumio01 volumio-remote-updater[784]: [2026-01-28 21:04:05] [connect] Successful connection Jan 28 21:04:05 volumio01 volumio[8617]: info: Volumio called home Jan 28 21:04:05 volumio01 volumio[8617]: info: Spotify config file written Jan 28 21:04:05 volumio01 sudo[8872]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/cp -r /data/plugins/user_interface/touch_display/iframe_keyboard_bridge/content.js /data/plugins/user_interface/touch_display/iframe_keyboard_bridge/manifest.json /data/volumiokioskextensions/IframeKeyboardBridge/ Jan 28 21:04:05 volumio01 sudo[8872]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:05 volumio01 sudo[8872]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:05 volumio01 sudo[8877]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 21:04:05 volumio01 sudo[8877]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:05 volumio01 volumio[8617]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Jan 28 21:04:05 volumio01 volumio[8617]: verbose: New Socket.io Connection to 192.168.178.129 from 192.168.178.100 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:147.0) Gecko/20100101 Firefox/147.0 Engine version: 3 Transport: polling Total Clients: 10 Jan 28 21:04:05 volumio01 volumio[8617]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Jan 28 21:04:05 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:05 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:05 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:05 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:05 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:05 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:05 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:05 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:05 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 21:04:05 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:05 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:05 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:05 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:05 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:05 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:05 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:05 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:05 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:05 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 21:04:05 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:05 volumio01 volumio[8617]: info: No need to fix Spotify hosts Jan 28 21:04:06 volumio01 volumio[8617]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Jan 28 21:04:06 volumio01 volumio[8617]: info: touch_display: IframeKeyboardBridge extension installed successfully Jan 28 21:04:06 volumio01 volumio[8617]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists Jan 28 21:04:06 volumio01 volumio[8617]: error: FusionDsp - ----failed to create fusiondspfifo :Error: Command failed: /bin/touch /tmp/fusiondsp_stream_params.log && /bin/chmod 666 /tmp/fusiondsp_stream_params.log && /bin/touch /tmp/camilladsp.log && /bin/chmod 666 /tmp/camilladsp.log && /usr/bin/mkfifo -m 646 /tmp/fusiondspfifo Jan 28 21:04:06 volumio01 volumio[8617]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists Jan 28 21:04:06 volumio01 volumio[8617]: info: camilladsp service started and running in background, instance 1 Jan 28 21:04:06 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:06 volumio01 volumio[8617]: info: FusionDsp - AAAAAAAAAAAAAA-> 22050 44100 48000 88200 96000 176400 192000 384000 <-AAAAAAAAAAAAA Jan 28 21:04:06 volumio01 volumio[8617]: info: FusionDsp loaded Jan 28 21:04:06 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 28 21:04:06 volumio01 volumio[8617]: error: FusionDsp - Socket connection not established Jan 28 21:04:06 volumio01 volumio[8617]: info: FusionDsp - Reporting Fusion DSP Enabled Jan 28 21:04:06 volumio01 volumio[8617]: info: Adding Signal Path Element [object Object] Jan 28 21:04:06 volumio01 volumio[8617]: info: Adding fusiondspeq DSP Signal Path Element Jan 28 21:04:06 volumio01 volumio[8617]: info: FusionDsp - ---- installed callbackRead Jan 28 21:04:06 volumio01 volumio[8617]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jan 28 21:04:06 volumio01 sudo[8904]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Jan 28 21:04:06 volumio01 sudo[8904]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:06 volumio01 sudo[8906]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+w /sys/class/backlight/rpi_backlight/brightness Jan 28 21:04:06 volumio01 sudo[8906]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:06 volumio01 sudo[8906]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:06 volumio01 volumio[8617]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 Jan 28 21:04:06 volumio01 volumio[8617]: info: touch_display: Raspberry Pi Foundation touch screen detected. Jan 28 21:04:06 volumio01 sudo[8911]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Jan 28 21:04:06 volumio01 sudo[8911]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:06 volumio01 systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 21:04:06 volumio01 systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 21:04:06 volumio01 volumio[8617]: info: CoreCommandRouter::volumioGetVisibleSources Jan 28 21:04:06 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 21:04:06 volumio01 sudo[8911]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:06 volumio01 volumio[8617]: info: CoreCommandRouter::volumioGetState Jan 28 21:04:06 volumio01 volumio[8617]: info: CorePlayQueue::getTrack 0 Jan 28 21:04:06 volumio01 sudo[8914]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Jan 28 21:04:06 volumio01 sudo[8914]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:06 volumio01 volumio[8617]: info: CoreCommandRouter::volumioGetQueue Jan 28 21:04:06 volumio01 volumio[8617]: info: CoreStateMachine::getQueue Jan 28 21:04:06 volumio01 volumio[8617]: info: CorePlayQueue::getQueue Jan 28 21:04:06 volumio01 volumio[8617]: info: Listing playlists Jan 28 21:04:06 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 28 21:04:06 volumio01 sudo[8914]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:07 volumio01 systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 21:04:07 volumio01 systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 21:04:07 volumio01 volumio-remote-updater[784]: [2026-01-28 21:04:07] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769630645 101 Jan 28 21:04:07 volumio01 volumio[8617]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 14 Jan 28 21:04:07 volumio01 volumio[8617]: error: FusionDsp - Reload WebSocket error: [object Object] Jan 28 21:04:07 volumio01 volumio[8617]: info: touch_display: File permissions for backlight brightness control set. Jan 28 21:04:07 volumio01 volumio[8617]: info: Starting Shairport Sync Jan 28 21:04:07 volumio01 volumio[8617]: info: Starting Shairport Sync Jan 28 21:04:07 volumio01 sudo[8843]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:07 volumio01 sudo[8919]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 21:04:07 volumio01 volumio[8617]: info: Starting Shairport Sync Jan 28 21:04:07 volumio01 sudo[8919]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:07 volumio01 sudo[8917]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 21:04:07 volumio01 systemd[1]: Reloading. Jan 28 21:04:07 volumio01 sudo[8917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:07 volumio01 sudo[8922]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 21:04:07 volumio01 sudo[8922]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:07 volumio01 sudo[8925]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 21:04:07 volumio01 sudo[8925]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:07 volumio01 volumio[8617]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set. Jan 28 21:04:07 volumio01 volumio[8617]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Jan 28 21:04:07 volumio01 volumio[8617]: info: Asound.conf file unchanged, so no further update is needed Jan 28 21:04:07 volumio01 volumio[8617]: info: Output device has changed, restarting MPD Jan 28 21:04:07 volumio01 volumio[8617]: info: Output device has changed, restarting Shairport Sync Jan 28 21:04:07 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:07 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 21:04:08 volumio01 sudo[8945]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 21:04:08 volumio01 sudo[8945]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:08 volumio01 sudo[8951]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 21:04:08 volumio01 sudo[8951]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:08 volumio01 sudo[8945]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:08 volumio01 volumio[8617]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 21:04:08 volumio01 volumio[8617]: info: Preparing to generate the ALSA configuration file Jan 28 21:04:08 volumio01 volumio[8617]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jan 28 21:04:08 volumio01 volumio[8617]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jan 28 21:04:08 volumio01 volumio[8617]: info: Reading ALSA contributions from plugins. Jan 28 21:04:08 volumio01 volumio[8617]: info: touch_display: systemctl daemon-reload succeeded. Jan 28 21:04:08 volumio01 mpd[8827]: 2026-01-28T21:04:08 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 21:04:08 volumio01 volumio[8617]: info: CoreCommandRouter::volumioGetState Jan 28 21:04:08 volumio01 volumio[8617]: info: CorePlayQueue::getTrack 0 Jan 28 21:04:08 volumio01 volumio[8617]: info: MPD Permissions set Jan 28 21:04:08 volumio01 sudo[8960]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Jan 28 21:04:08 volumio01 sudo[8960]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:08 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:08 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:08 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:08 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:08 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:08 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:08 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:08 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:08 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 21:04:08 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:08 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 28 21:04:08 volumio01 volumio[8617]: info: CoreCommandRouter::volumioGetVisibleSources Jan 28 21:04:08 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 21:04:08 volumio01 volumio[8617]: info: Listing playlists Jan 28 21:04:08 volumio01 volumio[8617]: info: CoreCommandRouter::volumioGetQueue Jan 28 21:04:08 volumio01 volumio[8617]: info: CoreStateMachine::getQueue Jan 28 21:04:08 volumio01 volumio[8617]: info: CorePlayQueue::getQueue Jan 28 21:04:08 volumio01 volumio[8617]: info: Starting Shairport Sync Jan 28 21:04:08 volumio01 volumio[8617]: info: Asound.conf file unchanged, so no further update is needed Jan 28 21:04:08 volumio01 volumio[8617]: info: Output device has changed, restarting MPD Jan 28 21:04:08 volumio01 volumio[8617]: info: Output device has changed, restarting Shairport Sync Jan 28 21:04:08 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:08 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 21:04:08 volumio01 sudo[8971]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 21:04:08 volumio01 sudo[8971]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:08 volumio01 sudo[8974]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 21:04:08 volumio01 sudo[8974]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:08 volumio01 sudo[8976]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 21:04:08 volumio01 sudo[8976]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:08 volumio01 sudo[8974]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:08 volumio01 volumio[8617]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 21:04:08 volumio01 volumio[8617]: info: MPD Permissions set Jan 28 21:04:08 volumio01 volumio[8617]: info: CoreCommandRouter::volumioGetState Jan 28 21:04:08 volumio01 volumio[8617]: info: CorePlayQueue::getTrack 0 Jan 28 21:04:08 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:08 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:08 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:08 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:08 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:08 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:08 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:08 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:09 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 21:04:09 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 21:04:09 volumio01 volumio[8617]: info: AutoStart - Check #2/60 - VOLUMIO_SYSTEM_STATUS = starting Jan 28 21:04:09 volumio01 volumio[8617]: info: Starting Shairport Sync Jan 28 21:04:09 volumio01 sudo[8992]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 21:04:09 volumio01 sudo[8992]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:09 volumio01 volumio[8617]: info: CoreCommandRouter::volumioSeek Jan 28 21:04:09 volumio01 volumio[8617]: info: CoreStateMachine::seek Jan 28 21:04:09 volumio01 volumio[8617]: info: CorePlayQueue::getTrack 0 Jan 28 21:04:09 volumio01 volumio[8617]: info: TRACKBLOCK {"uri":"mnt/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_L_refL.wav","service":"mpd","name":"512kMeasSweep_30_to_20k_44k_PCM16_L_refL","artist":"FusionDsp","album":"Test Signal","type":"track","tracknumber":0,"albumart":"/albumart?cacheid=923&web=FusionDsp/Test%20Signal/extralarge&path=%2FINTERNAL%2FFusionDsp%2Ftools&metadata=false","duration":13,"trackType":"wav"} Jan 28 21:04:09 volumio01 volumio[8617]: info: CoreStateMachine::startPlaybackTimer Jan 28 21:04:09 volumio01 volumio[8617]: info: CorePlayQueue::getTrack 0 Jan 28 21:04:09 volumio01 volumio[8617]: info: ControllerMpd::seek Jan 28 21:04:09 volumio01 volumio[8617]: error: Could not seek because there is no mpd connection Jan 28 21:04:09 volumio01 volumio[8617]: info: CoreStateMachine::pushState Jan 28 21:04:09 volumio01 volumio[8617]: info: CorePlayQueue::getTrack 0 Jan 28 21:04:09 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 21:04:09 volumio01 volumio[8617]: info: CoreCommandRouter::volumioPushState Jan 28 21:04:09 volumio01 volumio[8617]: info: PeppySpectrum ---peppyspectrum status stop Jan 28 21:04:09 volumio01 sudo[8995]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Jan 28 21:04:09 volumio01 sudo[8995]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:09 volumio01 systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 21:04:09 volumio01 systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 21:04:09 volumio01 systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 21:04:09 volumio01 systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 28 21:04:09 volumio01 volumio[8617]: info: CoreCommandRouter::volumioSeek Jan 28 21:04:09 volumio01 volumio[8617]: info: CoreStateMachine::seek Jan 28 21:04:09 volumio01 volumio[8617]: info: CorePlayQueue::getTrack 0 Jan 28 21:04:09 volumio01 volumio[8617]: info: TRACKBLOCK {"uri":"mnt/INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_L_refL.wav","service":"mpd","name":"512kMeasSweep_30_to_20k_44k_PCM16_L_refL","artist":"FusionDsp","album":"Test Signal","type":"track","tracknumber":0,"albumart":"/albumart?cacheid=923&web=FusionDsp/Test%20Signal/extralarge&path=%2FINTERNAL%2FFusionDsp%2Ftools&metadata=false","duration":13,"trackType":"wav"} Jan 28 21:04:09 volumio01 volumio[8617]: info: CoreStateMachine::startPlaybackTimer Jan 28 21:04:09 volumio01 volumio[8617]: info: CorePlayQueue::getTrack 0 Jan 28 21:04:09 volumio01 volumio[8617]: info: ControllerMpd::seek Jan 28 21:04:09 volumio01 volumio[8617]: error: Could not seek because there is no mpd connection Jan 28 21:04:09 volumio01 volumio[8617]: info: CoreStateMachine::pushState Jan 28 21:04:09 volumio01 volumio[8617]: info: CorePlayQueue::getTrack 0 Jan 28 21:04:09 volumio01 volumio[8617]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 21:04:09 volumio01 volumio[8617]: info: CoreCommandRouter::volumioPushState Jan 28 21:04:09 volumio01 volumio[8617]: info: PeppySpectrum ---peppyspectrum status stop Jan 28 21:04:09 volumio01 volumio[8617]: info: CorePlayQueue::getTrack 0 Jan 28 21:04:09 volumio01 volumio[8617]: info: CorePlayQueue::getTrack 1 Jan 28 21:04:09 volumio01 volumio[8617]: info: Prefetching next song Jan 28 21:04:09 volumio01 volumio[8617]: info: DOING PREFETCH IN MPD Jan 28 21:04:09 volumio01 volumio[8617]: verbose: ControllerMpd::sendMpdCommand add "INTERNAL/FusionDsp/tools/512kMeasSweep_30_to_20000_44k_PCM16_LR_refL.wav" Jan 28 21:04:09 volumio01 volumio[8617]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 21:04:09 volumio01 volumio[8617]: TypeError: Cannot read properties of undefined (reading 'then') Jan 28 21:04:09 volumio01 volumio[8617]: at ControllerMpd.sendMpdCommand (/volumio/app/plugins/music_service/mpd/index.js:332:6) Jan 28 21:04:09 volumio01 volumio[8617]: at ControllerMpd.prefetch (/volumio/app/plugins/music_service/mpd/index.js:3738:15) Jan 28 21:04:09 volumio01 volumio[8617]: at CoreStateMachine.increasePlaybackTimer (/volumio/app/statemachine.js:464:18) Jan 28 21:04:09 volumio01 volumio[8617]: at listOnTimeout (node:internal/timers:573:17) Jan 28 21:04:09 volumio01 volumio[8617]: at process.processTimers (node:internal/timers:514:7) Jan 28 21:04:09 volumio01 volumio[8617]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 21:04:10 volumio01 sudo[8998]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Jan 28 21:04:10 volumio01 sudo[8998]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:10 volumio01 systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 21:04:10 volumio01 sudo[8841]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:10 volumio01 sudo[8775]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:10 volumio01 sudo[8795]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:10 volumio01 systemd[1]: Starting apt-daily.service - Daily apt download activities... Jan 28 21:04:10 volumio01 systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 21:04:10 volumio01 sudo[8904]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:10 volumio01 sudo[8874]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:10 volumio01 systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 21:04:10 volumio01 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 21:04:10 volumio01 sudo[8960]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:10 volumio01 sudo[8925]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:10 volumio01 systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 21:04:10 volumio01 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 21:04:10 volumio01 systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 21:04:10 volumio01 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 21:04:10 volumio01 systemd[1]: shairport-sync.service: Consumed 36.367s CPU time. Jan 28 21:04:10 volumio01 systemd[1]: mpd.service: Deactivated successfully. Jan 28 21:04:10 volumio01 systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 21:04:10 volumio01 systemd[1]: mpd.service: Consumed 3.850s CPU time. Jan 28 21:04:11 volumio01 sudo[8839]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:11 volumio01 sudo[8995]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:11 volumio01 sudo[8998]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:11 volumio01 systemd[1]: mpd.socket: Deactivated successfully. Jan 28 21:04:11 volumio01 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 21:04:11 volumio01 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 21:04:11 volumio01 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 21:04:11 volumio01 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 21:04:11 volumio01 sudo[8877]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:11 volumio01 go-librespot[9016]: go-librespot daemon starting... Jan 28 21:04:11 volumio01 systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 21:04:11 volumio01 sudo[9020]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 21:03' Jan 28 21:04:11 volumio01 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 21:04:11 volumio01 sudo[9020]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 21:04:11 volumio01 sudo[8992]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:11 volumio01 sudo[8922]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:11 volumio01 sudo[8919]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:11 volumio01 sudo[8971]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:11 volumio01 go-librespot[9021]: time="2026-01-28T21:04:11+01:00" level=info msg="running go-librespot 0.6.2" Jan 28 21:04:11 volumio01 go-librespot[9021]: time="2026-01-28T21:04:11+01:00" level=debug msg="app state loaded" Jan 28 21:04:11 volumio01 go-librespot[9021]: time="2026-01-28T21:04:11+01:00" level=debug msg="stored credentials not found" Jan 28 21:04:11 volumio01 sudo[8917]: pam_unix(sudo:session): session closed for user root Jan 28 21:04:11 volumio01 go-librespot[9021]: time="2026-01-28T21:04:11+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 21:04:11 volumio01 sudo[9019]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 21:04:11 volumio01 sudo[9019]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 21:04:11 volumio01 sudo[9019]: pam_unix(sudo:session): session closed for user root 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="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"