-- Logs begin at Thu 2024-08-15 10:49:29 CEST, end at Sun 2024-08-25 10:57:55 CEST. --
Aug 25 10:56:03 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Aug 25 10:56:03 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Aug 25 10:56:03 volumio volumio[1057]: info: Discovery: Getting this device information
Aug 25 10:56:03 volumio volumio[1057]: info: CoreCommandRouter::volumioGetState
Aug 25 10:56:03 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Aug 25 10:56:06 volumio ntpd[779]: Soliciting pool server 2a01:4f8:200:1307::10
Aug 25 10:56:16 volumio volumio[1057]: info: CoreCommandRouter::volumioStop
Aug 25 10:56:16 volumio volumio[1057]: info: CoreStateMachine::stop
Aug 25 10:56:16 volumio volumio[1057]: info: CoreStateMachine::setConsumeUpdateService undefined
Aug 25 10:56:16 volumio volumio[1057]: info: CoreStateMachine::stPlaybackTimer
Aug 25 10:56:16 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:16 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:16 volumio volumio[1057]: info: CoreStateMachine::pushState
Aug 25 10:56:16 volumio volumio[1057]: info: CorePlayQueue::getTrack 0
Aug 25 10:56:16 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Aug 25 10:56:16 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState
Aug 25 10:56:16 volumio volumio[1057]: info: MRS: Pushing multiroomSync output update for this device
Aug 25 10:56:16 volumio volumio[1057]: info: MRS: Pushing multiroomSync output
Aug 25 10:56:16 volumio volumio[1057]: info: CoreStateMachine::serviceStop
Aug 25 10:56:16 volumio volumio[1057]: info: CorePlayQueue::getTrack 0
Aug 25 10:56:16 volumio volumio[1057]: info: CoreCommandRouter::serviceStop
Aug 25 10:56:16 volumio volumio[1057]: info: [1724576176625] ControllerWebradio::stop
Aug 25 10:56:16 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand stop
Aug 25 10:56:16 volumio volumio[1057]: info:
Aug 25 10:56:16 volumio volumio[1057]: ---------------------------- MPD announces state update: player
Aug 25 10:56:16 volumio volumio[1057]: info: sendMpdCommand stop took 29 milliseconds
Aug 25 10:56:16 volumio volumio[1057]: info: ControllerMpd::getState
Aug 25 10:56:16 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status
Aug 25 10:56:16 volumio volumio[1057]: info: sendMpdCommand status took 1 milliseconds
Aug 25 10:56:16 volumio volumio[1057]: verbose: ControllerMpd::parseState
Aug 25 10:56:16 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 25 10:56:16 volumio volumio[1057]: info: sendMpdCommand playlistinfo took 1 milliseconds
Aug 25 10:56:16 volumio volumio[1057]: verbose: ControllerMpd::parseTrackInfo
Aug 25 10:56:16 volumio volumio[1057]: info: ControllerMpd::pushState
Aug 25 10:56:16 volumio volumio[1057]: info: CoreCommandRouter::servicePushState
Aug 25 10:56:16 volumio volumio[1057]: info: CoreStateMachine::pushState
Aug 25 10:56:16 volumio volumio[1057]: info: CorePlayQueue::getTrack 0
Aug 25 10:56:16 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState
Aug 25 10:56:16 volumio volumio[1057]: info: MRS: Pushing multiroomSync output update for this device
Aug 25 10:56:16 volumio volumio[1057]: info: MRS: Pushing multiroomSync output
Aug 25 10:56:16 volumio volumio[1057]: info: CorePlayQueue::getTrack 0
Aug 25 10:56:16 volumio volumio[1057]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd
Aug 25 10:56:16 volumio volumio[1057]: info: ------------------------------ 18ms
Aug 25 10:56:24 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Aug 25 10:56:24 volumio volumio[1057]: info: CURURI: music-library
Aug 25 10:56:24 volumio volumio[1057]: error: Failed LSINFO: null
Aug 25 10:56:24 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:28 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:33 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Aug 25 10:56:33 volumio volumio[1057]: info: CURURI: playlists
Aug 25 10:56:33 volumio volumio[1057]: info: Listing playlists
Aug 25 10:56:33 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:33 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Aug 25 10:56:33 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Aug 25 10:56:33 volumio volumio[1057]: info: Discovery: Getting this device information
Aug 25 10:56:33 volumio volumio[1057]: info: CoreCommandRouter::volumioGetState
Aug 25 10:56:33 volumio volumio[1057]: info: CorePlayQueue::getTrack 0
Aug 25 10:56:33 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Aug 25 10:56:36 volumio volumio[1057]: info: CoreCommandRouter::volumioReplaceandPlayItems
Aug 25 10:56:36 volumio volumio[1057]: info: CoreStateMachine::ClearQueue
Aug 25 10:56:36 volumio volumio[1057]: info: CoreStateMachine::stop
Aug 25 10:56:36 volumio volumio[1057]: info: CoreStateMachine::setConsumeUpdateService undefined
Aug 25 10:56:36 volumio volumio[1057]: info: CorePlayQueue::clearPlayQueue
Aug 25 10:56:36 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:36 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:36 volumio volumio[1057]: info: Play playlist Sade
Aug 25 10:56:36 volumio volumio[1057]: info: CoreCommandRouter::volumioClearQueue
Aug 25 10:56:36 volumio volumio[1057]: info: CoreStateMachine::ClearQueue
Aug 25 10:56:36 volumio volumio[1057]: info: CoreStateMachine::stop
Aug 25 10:56:36 volumio volumio[1057]: info: CoreStateMachine::setConsumeUpdateService undefined
Aug 25 10:56:36 volumio volumio[1057]: info: CorePlayQueue::clearPlayQueue
Aug 25 10:56:36 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:36 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState
Aug 25 10:56:36 volumio volumio[1057]: info: MRS: Pushing multiroomSync output update for this device
Aug 25 10:56:36 volumio volumio[1057]: info: MRS: Pushing multiroomSync output
Aug 25 10:56:36 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:36 volumio volumio[1057]: info: CoreCommandRouter::volumioAddQueueItems
Aug 25 10:56:36 volumio volumio[1057]: info: CoreStateMachine::addQueueItems
Aug 25 10:56:36 volumio volumio[1057]: info: CorePlayQueue::addQueueItems
Aug 25 10:56:36 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:36 volumio volumio[1057]: info: Adding Item to queue: tidal://song/149575765
Aug 25 10:56:36 volumio volumio[1057]: info: Exploding uri tidal://song/149575765 in service tidal
Aug 25 10:56:37 volumio volumio[1057]: info: explodeTIDALUri took 290 milliseconds
Aug 25 10:56:37 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:37 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:37 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:37 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:37 volumio volumio[1057]: info: CoreCommandRouter::volumioPlay
Aug 25 10:56:37 volumio volumio[1057]: info: CoreStateMachine::play index 0
Aug 25 10:56:37 volumio volumio[1057]: info: CoreStateMachine::setConsumeUpdateService undefined
Aug 25 10:56:37 volumio volumio[1057]: info: CoreStateMachine::stop
Aug 25 10:56:37 volumio volumio[1057]: info: CoreStateMachine::setConsumeUpdateService undefined
Aug 25 10:56:37 volumio volumio[1057]: info: CoreStateMachine::play index undefined
Aug 25 10:56:37 volumio volumio[1057]: info: CoreStateMachine::setConsumeUpdateService undefined
Aug 25 10:56:37 volumio volumio[1057]: info: CorePlayQueue::getTrack 0
Aug 25 10:56:37 volumio volumio[1057]: info: CoreStateMachine::startPlaybackTimer
Aug 25 10:56:37 volumio volumio[1057]: info: CorePlayQueue::getTrack 0
Aug 25 10:56:37 volumio volumio[1057]: info: CoreCommandRouter::volumioGetVisibleSources
Aug 25 10:56:37 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Aug 25 10:56:37 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Aug 25 10:56:37 volumio volumio[1057]: info: METAVOLUMIO: Retrieving similar tracks from metavolumio
Aug 25 10:56:37 volumio volumio[1057]: info: [1724576197017] ControllerTidal::clearAddPlayTrack
Aug 25 10:56:37 volumio volumio[1057]: info: Getting stream with soundQuality HIGHEST_POSSIBLE
Aug 25 10:56:37 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand stop
Aug 25 10:56:37 volumio volumio[1057]: info: sendMpdCommand stop took 4 milliseconds
Aug 25 10:56:37 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand clear
Aug 25 10:56:37 volumio volumio[1057]: info:
Aug 25 10:56:37 volumio volumio[1057]: ---------------------------- MPD announces system playlist update
Aug 25 10:56:37 volumio volumio[1057]: info: Ignoring MPD Status Update
Aug 25 10:56:37 volumio volumio[1057]: info: sendMpdCommand clear took 6 milliseconds
Aug 25 10:56:37 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/149575765&soundQuality=HIGHEST_POSSIBLE"
Aug 25 10:56:37 volumio volumio[1057]: error: updateQueue error: null
Aug 25 10:56:37 volumio volumio[1057]: info:
Aug 25 10:56:37 volumio volumio[1057]: ---------------------------- MPD announces system playlist update
Aug 25 10:56:37 volumio volumio[1057]: info: Ignoring MPD Status Update
Aug 25 10:56:37 volumio volumio[1057]: info: ------------------------------ 3ms
Aug 25 10:56:37 volumio volumio[1057]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/149575765&soundQuality=HIGHEST_POSSIBLE" took 2 milliseconds
Aug 25 10:56:37 volumio volumio[1057]: info: CoreStateMachine::setConsumeUpdateService mpd
Aug 25 10:56:37 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand play
Aug 25 10:56:37 volumio volumio[1057]: info: ------------------------------ 3ms
Aug 25 10:56:37 volumio volumio[1057]: info: sendMpdCommand play took 2 milliseconds
Aug 25 10:56:37 volumio volumio[1057]: STREAMING PROXY: Handling url /?data=tidal://song/149575765&soundQuality=HIGHEST_POSSIBLE
Aug 25 10:56:37 volumio volumio[1057]: info: Executing endpoint getStreamUrltidal
Aug 25 10:56:37 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI
Aug 25 10:56:37 volumio volumio[1057]: info: getStreamUrl took 276 milliseconds
Aug 25 10:56:37 volumio volumio[1057]: error: Could not get TIDAL Stream URL
Aug 25 10:56:37 volumio volumio[1057]: error: Failed to retrieve real stream URL
Aug 25 10:56:37 volumio volumio[1057]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl
Aug 25 10:56:39 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , search
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: youtube2 , search
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: spop , search
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: tidal , search
Aug 25 10:56:39 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::volumioGetQueue
Aug 25 10:56:39 volumio volumio[1057]: info: CoreStateMachine::getQueue
Aug 25 10:56:39 volumio volumio[1057]: info: CorePlayQueue::getQueue
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::volumioAddQueueItems
Aug 25 10:56:39 volumio volumio[1057]: info: CoreStateMachine::addQueueItems
Aug 25 10:56:39 volumio volumio[1057]: info: CorePlayQueue::addQueueItems
Aug 25 10:56:39 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:39 volumio volumio[1057]: info: Adding Item to queue: spotify:track:4J7s7j5ulwElPG7HaGQDXR
Aug 25 10:56:39 volumio volumio[1057]: info: Exploding uri spotify:track:4J7s7j5ulwElPG7HaGQDXR in service spop
Aug 25 10:56:39 volumio volumio[1057]: SPOTIFY: EXPLODING URI:spotify:track:4J7s7j5ulwElPG7HaGQDXR
Aug 25 10:56:39 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , search
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: youtube2 , search
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: spop , search
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: tidal , search
Aug 25 10:56:39 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , search
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: youtube2 , search
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: spop , search
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: tidal , search
Aug 25 10:56:39 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , search
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: youtube2 , search
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: spop , search
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: tidal , search
Aug 25 10:56:39 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::volumioGetQueue
Aug 25 10:56:39 volumio volumio[1057]: info: CoreStateMachine::getQueue
Aug 25 10:56:39 volumio volumio[1057]: info: CorePlayQueue::getQueue
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::volumioAddQueueItems
Aug 25 10:56:39 volumio volumio[1057]: info: CoreStateMachine::addQueueItems
Aug 25 10:56:39 volumio volumio[1057]: info: CorePlayQueue::addQueueItems
Aug 25 10:56:39 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:39 volumio volumio[1057]: info: Adding Item to queue: spotify:track:7H3ojI1BsVy0dEJENqMt1k
Aug 25 10:56:39 volumio volumio[1057]: info: Exploding uri spotify:track:7H3ojI1BsVy0dEJENqMt1k in service spop
Aug 25 10:56:39 volumio volumio[1057]: SPOTIFY: EXPLODING URI:spotify:track:7H3ojI1BsVy0dEJENqMt1k
Aug 25 10:56:39 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::volumioGetQueue
Aug 25 10:56:39 volumio volumio[1057]: info: CoreStateMachine::getQueue
Aug 25 10:56:39 volumio volumio[1057]: info: CorePlayQueue::getQueue
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::volumioAddQueueItems
Aug 25 10:56:39 volumio volumio[1057]: info: CoreStateMachine::addQueueItems
Aug 25 10:56:39 volumio volumio[1057]: info: CorePlayQueue::addQueueItems
Aug 25 10:56:39 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:39 volumio volumio[1057]: info: Adding Item to queue: spotify:track:1SvET7grrtsHT0CkyJjJcZ
Aug 25 10:56:39 volumio volumio[1057]: info: Exploding uri spotify:track:1SvET7grrtsHT0CkyJjJcZ in service spop
Aug 25 10:56:39 volumio volumio[1057]: SPOTIFY: EXPLODING URI:spotify:track:1SvET7grrtsHT0CkyJjJcZ
Aug 25 10:56:39 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::volumioGetQueue
Aug 25 10:56:39 volumio volumio[1057]: info: CoreStateMachine::getQueue
Aug 25 10:56:39 volumio volumio[1057]: info: CorePlayQueue::getQueue
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::volumioAddQueueItems
Aug 25 10:56:39 volumio volumio[1057]: info: CoreStateMachine::addQueueItems
Aug 25 10:56:39 volumio volumio[1057]: info: CorePlayQueue::addQueueItems
Aug 25 10:56:39 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:39 volumio volumio[1057]: info: Adding Item to queue: spotify:track:65krtHkaYLPr0mEbjL61UP
Aug 25 10:56:39 volumio volumio[1057]: info: Exploding uri spotify:track:65krtHkaYLPr0mEbjL61UP in service spop
Aug 25 10:56:39 volumio volumio[1057]: SPOTIFY: EXPLODING URI:spotify:track:65krtHkaYLPr0mEbjL61UP
Aug 25 10:56:39 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::volumioGetQueue
Aug 25 10:56:39 volumio volumio[1057]: info: CoreStateMachine::getQueue
Aug 25 10:56:39 volumio volumio[1057]: info: CorePlayQueue::getQueue
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::volumioAddQueueItems
Aug 25 10:56:39 volumio volumio[1057]: info: CoreStateMachine::addQueueItems
Aug 25 10:56:39 volumio volumio[1057]: info: CorePlayQueue::addQueueItems
Aug 25 10:56:39 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:39 volumio volumio[1057]: info: Adding Item to queue: spotify:track:5DYD5pUUnf3MT6LafqPqOt
Aug 25 10:56:39 volumio volumio[1057]: info: Exploding uri spotify:track:5DYD5pUUnf3MT6LafqPqOt in service spop
Aug 25 10:56:39 volumio volumio[1057]: SPOTIFY: EXPLODING URI:spotify:track:5DYD5pUUnf3MT6LafqPqOt
Aug 25 10:56:39 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::volumioGetQueue
Aug 25 10:56:39 volumio volumio[1057]: info: CoreStateMachine::getQueue
Aug 25 10:56:39 volumio volumio[1057]: info: CorePlayQueue::getQueue
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::volumioAddQueueItems
Aug 25 10:56:39 volumio volumio[1057]: info: CoreStateMachine::addQueueItems
Aug 25 10:56:39 volumio volumio[1057]: info: CorePlayQueue::addQueueItems
Aug 25 10:56:39 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:39 volumio volumio[1057]: info: Adding Item to queue: spotify:track:7pd7fTNMtn4jRv80CSdgcq
Aug 25 10:56:39 volumio volumio[1057]: info: Exploding uri spotify:track:7pd7fTNMtn4jRv80CSdgcq in service spop
Aug 25 10:56:39 volumio volumio[1057]: SPOTIFY: EXPLODING URI:spotify:track:7pd7fTNMtn4jRv80CSdgcq
Aug 25 10:56:39 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::volumioGetQueue
Aug 25 10:56:39 volumio volumio[1057]: info: CoreStateMachine::getQueue
Aug 25 10:56:39 volumio volumio[1057]: info: CorePlayQueue::getQueue
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::volumioAddQueueItems
Aug 25 10:56:39 volumio volumio[1057]: info: CoreStateMachine::addQueueItems
Aug 25 10:56:39 volumio volumio[1057]: info: CorePlayQueue::addQueueItems
Aug 25 10:56:39 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:39 volumio volumio[1057]: info: Adding Item to queue: spotify:track:4tReFKumS5bcFahdXDiM1b
Aug 25 10:56:39 volumio volumio[1057]: info: Exploding uri spotify:track:4tReFKumS5bcFahdXDiM1b in service spop
Aug 25 10:56:39 volumio volumio[1057]: SPOTIFY: EXPLODING URI:spotify:track:4tReFKumS5bcFahdXDiM1b
Aug 25 10:56:39 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , search
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: youtube2 , search
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: spop , search
Aug 25 10:56:39 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: tidal , search
Aug 25 10:56:40 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::volumioGetQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CoreStateMachine::getQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::getQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::volumioAddQueueItems
Aug 25 10:56:40 volumio volumio[1057]: info: CoreStateMachine::addQueueItems
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::addQueueItems
Aug 25 10:56:40 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:40 volumio volumio[1057]: info: Adding Item to queue: spotify:track:7pLuEMFougkSHXrPBtNxTR
Aug 25 10:56:40 volumio volumio[1057]: info: Exploding uri spotify:track:7pLuEMFougkSHXrPBtNxTR in service spop
Aug 25 10:56:40 volumio volumio[1057]: SPOTIFY: EXPLODING URI:spotify:track:7pLuEMFougkSHXrPBtNxTR
Aug 25 10:56:40 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::volumioGetQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CoreStateMachine::getQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::getQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::volumioAddQueueItems
Aug 25 10:56:40 volumio volumio[1057]: info: CoreStateMachine::addQueueItems
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::addQueueItems
Aug 25 10:56:40 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:40 volumio volumio[1057]: info: Adding Item to queue: spotify:track:0sKfhhj6hYyJIXnTiZV9vf
Aug 25 10:56:40 volumio volumio[1057]: info: Exploding uri spotify:track:0sKfhhj6hYyJIXnTiZV9vf in service spop
Aug 25 10:56:40 volumio volumio[1057]: SPOTIFY: EXPLODING URI:spotify:track:0sKfhhj6hYyJIXnTiZV9vf
Aug 25 10:56:40 volumio volumio[1057]: info: PARSING RESPONSE ERROR Error: Album:Error: [2@0] {} Too many arguments
Aug 25 10:56:40 volumio volumio[1057]: info: PARSING RESPONSE ERROR Error: Album:Error: [2@0] {} Too many arguments
Aug 25 10:56:40 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , search
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: youtube2 , search
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: spop , search
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: tidal , search
Aug 25 10:56:40 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , search
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: youtube2 , search
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: spop , search
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: tidal , search
Aug 25 10:56:40 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::volumioGetQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CoreStateMachine::getQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::getQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::volumioAddQueueItems
Aug 25 10:56:40 volumio volumio[1057]: info: CoreStateMachine::addQueueItems
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::addQueueItems
Aug 25 10:56:40 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:40 volumio volumio[1057]: info: Adding Item to queue: spotify:track:22QiTJqDn1BIRSh4mkNJ5w
Aug 25 10:56:40 volumio volumio[1057]: info: Exploding uri spotify:track:22QiTJqDn1BIRSh4mkNJ5w in service spop
Aug 25 10:56:40 volumio volumio[1057]: SPOTIFY: EXPLODING URI:spotify:track:22QiTJqDn1BIRSh4mkNJ5w
Aug 25 10:56:40 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::volumioGetQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CoreStateMachine::getQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::getQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::volumioAddQueueItems
Aug 25 10:56:40 volumio volumio[1057]: info: CoreStateMachine::addQueueItems
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::addQueueItems
Aug 25 10:56:40 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:40 volumio volumio[1057]: info: Adding Item to queue: spotify:track:0bgsj8kz5zWbQ6njk2Oqoz
Aug 25 10:56:40 volumio volumio[1057]: info: Exploding uri spotify:track:0bgsj8kz5zWbQ6njk2Oqoz in service spop
Aug 25 10:56:40 volumio volumio[1057]: SPOTIFY: EXPLODING URI:spotify:track:0bgsj8kz5zWbQ6njk2Oqoz
Aug 25 10:56:40 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , search
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: youtube2 , search
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: spop , search
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: tidal , search
Aug 25 10:56:40 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , search
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: youtube2 , search
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: spop , search
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: tidal , search
Aug 25 10:56:40 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::volumioGetQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CoreStateMachine::getQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::getQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::volumioAddQueueItems
Aug 25 10:56:40 volumio volumio[1057]: info: CoreStateMachine::addQueueItems
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::addQueueItems
Aug 25 10:56:40 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:40 volumio volumio[1057]: info: Adding Item to queue: spotify:track:1oaaSrDJimABpOdCEbw2DJ
Aug 25 10:56:40 volumio volumio[1057]: info: Exploding uri spotify:track:1oaaSrDJimABpOdCEbw2DJ in service spop
Aug 25 10:56:40 volumio volumio[1057]: SPOTIFY: EXPLODING URI:spotify:track:1oaaSrDJimABpOdCEbw2DJ
Aug 25 10:56:40 volumio volumio[1057]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5DYD5pUUnf3MT6LafqPqOt","service":"spop","name":"When Am I Going to Make a Living","artist":"Sade","album":"Diamond Life","type":"song","duration":205,"albumart":"https://i.scdn.co/image/ab67616d0000b273ad27e16c5f844ea1ad6797cd","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:40 volumio volumio[1057]: info: searchTIDALUri took 586 milliseconds
Aug 25 10:56:40 volumio volumio[1057]: info: search took 586 milliseconds
Aug 25 10:56:40 volumio volumio[1057]: error: An error occurred while searching WebapiRegularError: An error occurred while communicating with Spotify's Web API.
Aug 25 10:56:40 volumio volumio[1057]: Details: Bad request..
Aug 25 10:56:40 volumio volumio[1057]: error: Failed search in plugin spop:
Aug 25 10:56:40 volumio volumio[1057]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:65krtHkaYLPr0mEbjL61UP","service":"spop","name":"Kiss of Life","artist":"Sade","album":"The Best of Sade","type":"song","duration":251,"albumart":"https://i.scdn.co/image/ab67616d0000b2735e25e034e25258b356774c79","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:40 volumio volumio[1057]: error: An error occurred while searching WebapiRegularError: An error occurred while communicating with Spotify's Web API.
Aug 25 10:56:40 volumio volumio[1057]: Details: Bad request..
Aug 25 10:56:40 volumio volumio[1057]: error: Failed search in plugin spop:
Aug 25 10:56:40 volumio volumio[1057]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1SvET7grrtsHT0CkyJjJcZ","service":"spop","name":"Is It a Crime","artist":"Sade","album":"The Best of Sade","type":"song","duration":381,"albumart":"https://i.scdn.co/image/ab67616d0000b2735e25e034e25258b356774c79","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:40 volumio volumio[1057]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7H3ojI1BsVy0dEJENqMt1k","service":"spop","name":"By Your Side","artist":"Sade","album":"Lovers Rock","type":"song","duration":274,"albumart":"https://i.scdn.co/image/ab67616d0000b27320fc6951e4d293707de2434c","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:40 volumio volumio[1057]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4tReFKumS5bcFahdXDiM1b","service":"spop","name":"Paradise","artist":"Sade","album":"The Best of Sade","type":"song","duration":217,"albumart":"https://i.scdn.co/image/ab67616d0000b2735e25e034e25258b356774c79","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:40 volumio volumio[1057]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0bgsj8kz5zWbQ6njk2Oqoz","service":"spop","name":"Soldier of Love","artist":"Sade","album":"Soldier of Love","type":"song","duration":356,"albumart":"https://i.scdn.co/image/ab67616d0000b27398da02db8bb9253c3367e41a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:40 volumio volumio[1057]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7pd7fTNMtn4jRv80CSdgcq","service":"spop","name":"Why Can't We Live Together","artist":"Sade","album":"Diamond Life","type":"song","duration":328,"albumart":"https://i.scdn.co/image/ab67616d0000b273ad27e16c5f844ea1ad6797cd","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:40 volumio volumio[1057]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0sKfhhj6hYyJIXnTiZV9vf","service":"spop","name":"The Sweetest Taboo","artist":"Sade","album":"Promise","type":"song","duration":277,"albumart":"https://i.scdn.co/image/ab67616d0000b273584302fee10c0d0a12c40c97","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:40 volumio volumio[1057]: info: searchTIDALUri took 558 milliseconds
Aug 25 10:56:40 volumio volumio[1057]: info: search took 559 milliseconds
Aug 25 10:56:40 volumio volumio[1057]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4J7s7j5ulwElPG7HaGQDXR","service":"spop","name":"Pearls","artist":"Sade","album":"Love Deluxe","type":"song","duration":273,"albumart":"https://i.scdn.co/image/ab67616d0000b273ee65bbd54f993b5f01d5c511","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:40 volumio volumio[1057]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1oaaSrDJimABpOdCEbw2DJ","service":"spop","name":"No Ordinary Love","artist":"Sade","album":"Love Deluxe","type":"song","duration":440,"albumart":"https://i.scdn.co/image/ab67616d0000b273ee65bbd54f993b5f01d5c511","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:40 volumio volumio[1057]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7pLuEMFougkSHXrPBtNxTR","service":"spop","name":"Smooth Operator","artist":"Sade","album":"Diamond Life","type":"song","duration":298,"albumart":"https://i.scdn.co/image/ab67616d0000b273ad27e16c5f844ea1ad6797cd","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:40 volumio volumio[1057]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:22QiTJqDn1BIRSh4mkNJ5w","service":"spop","name":"Cherish the Day","artist":"Sade","album":"Love Deluxe","type":"song","duration":332,"albumart":"https://i.scdn.co/image/ab67616d0000b273ee65bbd54f993b5f01d5c511","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:40 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:40 volumio volumio[1057]: info: searchTIDALUri took 637 milliseconds
Aug 25 10:56:40 volumio volumio[1057]: info: search took 637 milliseconds
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::volumioPlay
Aug 25 10:56:40 volumio volumio[1057]: info: CoreStateMachine::play index undefined
Aug 25 10:56:40 volumio volumio[1057]: info: CoreStateMachine::setConsumeUpdateService undefined
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::getTrack 0
Aug 25 10:56:40 volumio volumio[1057]: info: CoreStateMachine::startPlaybackTimer
Aug 25 10:56:40 volumio volumio[1057]: info: CorePlayQueue::getTrack 0
Aug 25 10:56:40 volumio volumio[1057]: info: [1724576200786] ControllerTidal::clearAddPlayTrack
Aug 25 10:56:40 volumio volumio[1057]: info: Getting stream with soundQuality HIGHEST_POSSIBLE
Aug 25 10:56:40 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand stop
Aug 25 10:56:40 volumio volumio[1057]: info:
Aug 25 10:56:40 volumio volumio[1057]: ---------------------------- MPD announces state update: player
Aug 25 10:56:40 volumio volumio[1057]: info: sendMpdCommand stop took 2 milliseconds
Aug 25 10:56:40 volumio volumio[1057]: info: ControllerMpd::getState
Aug 25 10:56:40 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status
Aug 25 10:56:40 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand clear
Aug 25 10:56:40 volumio volumio[1057]: info:
Aug 25 10:56:40 volumio volumio[1057]: ---------------------------- MPD announces system playlist update
Aug 25 10:56:40 volumio volumio[1057]: info: Ignoring MPD Status Update
Aug 25 10:56:40 volumio volumio[1057]: info: sendMpdCommand status took 2 milliseconds
Aug 25 10:56:40 volumio volumio[1057]: info: sendMpdCommand clear took 1 milliseconds
Aug 25 10:56:40 volumio volumio[1057]: verbose: ControllerMpd::parseState
Aug 25 10:56:40 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 25 10:56:40 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/149575765&soundQuality=HIGHEST_POSSIBLE"
Aug 25 10:56:40 volumio volumio[1057]: error: updateQueue error: null
Aug 25 10:56:40 volumio volumio[1057]: info:
Aug 25 10:56:40 volumio volumio[1057]: ---------------------------- MPD announces system playlist update
Aug 25 10:56:40 volumio volumio[1057]: info: Ignoring MPD Status Update
Aug 25 10:56:40 volumio volumio[1057]: info: ------------------------------ 8ms
Aug 25 10:56:40 volumio volumio[1057]: info: sendMpdCommand playlistinfo took 6 milliseconds
Aug 25 10:56:40 volumio volumio[1057]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/149575765&soundQuality=HIGHEST_POSSIBLE" took 6 milliseconds
Aug 25 10:56:40 volumio volumio[1057]: verbose: ControllerMpd::parseTrackInfo
Aug 25 10:56:40 volumio volumio[1057]: info: CoreStateMachine::setConsumeUpdateService mpd
Aug 25 10:56:40 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand play
Aug 25 10:56:40 volumio volumio[1057]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined
Aug 25 10:56:40 volumio volumio[1057]: info: ------------------------------ 12ms
Aug 25 10:56:40 volumio volumio[1057]: STREAMING PROXY: Handling url /?data=tidal://song/149575765&soundQuality=HIGHEST_POSSIBLE
Aug 25 10:56:40 volumio volumio[1057]: info: ------------------------------ 11ms
Aug 25 10:56:40 volumio volumio[1057]: info: sendMpdCommand play took 9 milliseconds
Aug 25 10:56:40 volumio volumio[1057]: info: Executing endpoint getStreamUrltidal
Aug 25 10:56:40 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI
Aug 25 10:56:41 volumio volumio[1057]: info: searchTIDALUri took 1007 milliseconds
Aug 25 10:56:41 volumio volumio[1057]: info: search took 1008 milliseconds
Aug 25 10:56:41 volumio volumio[1057]: info: searchTIDALUri took 1258 milliseconds
Aug 25 10:56:41 volumio volumio[1057]: info: search took 1258 milliseconds
Aug 25 10:56:41 volumio volumio[1057]: info: All search sources collected, pushing search results
Aug 25 10:56:41 volumio volumio[1057]: info: searchTIDALUri took 1054 milliseconds
Aug 25 10:56:41 volumio volumio[1057]: info: search took 1055 milliseconds
Aug 25 10:56:41 volumio volumio[1057]: info: searchTIDALUri took 1177 milliseconds
Aug 25 10:56:41 volumio volumio[1057]: info: search took 1177 milliseconds
Aug 25 10:56:41 volumio volumio[1057]: info: All search sources collected, pushing search results
Aug 25 10:56:41 volumio volumio[1057]: info: CoreCommandRouter::volumioGetQueue
Aug 25 10:56:41 volumio volumio[1057]: info: CoreStateMachine::getQueue
Aug 25 10:56:41 volumio volumio[1057]: info: CorePlayQueue::getQueue
Aug 25 10:56:41 volumio volumio[1057]: info: CoreCommandRouter::volumioAddQueueItems
Aug 25 10:56:41 volumio volumio[1057]: info: CoreStateMachine::addQueueItems
Aug 25 10:56:41 volumio volumio[1057]: info: CorePlayQueue::addQueueItems
Aug 25 10:56:41 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:41 volumio volumio[1057]: info: Adding Item to queue: tidal://song/149575025
Aug 25 10:56:41 volumio volumio[1057]: info: Exploding uri tidal://song/149575025 in service tidal
Aug 25 10:56:41 volumio volumio[1057]: info: searchTIDALUri took 1043 milliseconds
Aug 25 10:56:41 volumio volumio[1057]: info: search took 1044 milliseconds
Aug 25 10:56:41 volumio volumio[1057]: SearchHeader changed!
Aug 25 10:56:41 volumio volumio[1057]: The following keys where altered: chip_bar
Aug 25 10:56:41 volumio volumio[1057]: The class has changed to:
Aug 25 10:56:41 volumio volumio[1057]: class SearchHeader extends YTNode {
Aug 25 10:56:41 volumio volumio[1057]: static type = 'SearchHeader';
Aug 25 10:56:41 volumio volumio[1057]: search_filter_button: YTNodes.Button | null;
Aug 25 10:56:41 volumio volumio[1057]: chip_bar?: YTNodes.ChipCloud | null;
Aug 25 10:56:41 volumio volumio[1057]: constructor(data: RawNode) {
Aug 25 10:56:41 volumio volumio[1057]: super();
Aug 25 10:56:41 volumio volumio[1057]: this.search_filter_button = Parser.parseItem(data.searchFilterButton, [ YTNodes.Button ]);
Aug 25 10:56:41 volumio volumio[1057]: this.chip_bar = Reflect.has(data, 'chipBar') ? Parser.parseItem(data.chipBar, [ YTNodes.ChipCloud ]) : undefined;
Aug 25 10:56:41 volumio volumio[1057]: }
Aug 25 10:56:41 volumio volumio[1057]: }
Aug 25 10:56:41 volumio volumio[1057]: info: All search sources collected, pushing search results
Aug 25 10:56:41 volumio volumio[1057]: info: getStreamUrl took 382 milliseconds
Aug 25 10:56:41 volumio volumio[1057]: error: Could not get TIDAL Stream URL
Aug 25 10:56:41 volumio volumio[1057]: error: Failed to retrieve real stream URL
Aug 25 10:56:41 volumio volumio[1057]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl
Aug 25 10:56:41 volumio volumio[1057]: SearchHeader changed!
Aug 25 10:56:41 volumio volumio[1057]: The following keys where altered: chip_bar
Aug 25 10:56:41 volumio volumio[1057]: The class has changed to:
Aug 25 10:56:41 volumio volumio[1057]: class SearchHeader extends YTNode {
Aug 25 10:56:41 volumio volumio[1057]: static type = 'SearchHeader';
Aug 25 10:56:41 volumio volumio[1057]: search_filter_button: YTNodes.Button | null;
Aug 25 10:56:41 volumio volumio[1057]: chip_bar?: YTNodes.ChipCloud | null;
Aug 25 10:56:41 volumio volumio[1057]: constructor(data: RawNode) {
Aug 25 10:56:41 volumio volumio[1057]: super();
Aug 25 10:56:41 volumio volumio[1057]: this.search_filter_button = Parser.parseItem(data.searchFilterButton, [ YTNodes.Button ]);
Aug 25 10:56:41 volumio volumio[1057]: this.chip_bar = Reflect.has(data, 'chipBar') ? Parser.parseItem(data.chipBar, [ YTNodes.ChipCloud ]) : undefined;
Aug 25 10:56:41 volumio volumio[1057]: }
Aug 25 10:56:41 volumio volumio[1057]: }
Aug 25 10:56:41 volumio volumio[1057]: info: All search sources collected, pushing search results
Aug 25 10:56:41 volumio volumio[1057]: info: All search sources collected, pushing search results
Aug 25 10:56:41 volumio volumio[1057]: info: All search sources collected, pushing search results
Aug 25 10:56:41 volumio volumio[1057]: SearchHeader changed!
Aug 25 10:56:41 volumio volumio[1057]: The following keys where altered: chip_bar
Aug 25 10:56:41 volumio volumio[1057]: The class has changed to:
Aug 25 10:56:41 volumio volumio[1057]: class SearchHeader extends YTNode {
Aug 25 10:56:41 volumio volumio[1057]: static type = 'SearchHeader';
Aug 25 10:56:41 volumio volumio[1057]: search_filter_button: YTNodes.Button | null;
Aug 25 10:56:41 volumio volumio[1057]: chip_bar?: YTNodes.ChipCloud | null;
Aug 25 10:56:41 volumio volumio[1057]: constructor(data: RawNode) {
Aug 25 10:56:41 volumio volumio[1057]: super();
Aug 25 10:56:41 volumio volumio[1057]: this.search_filter_button = Parser.parseItem(data.searchFilterButton, [ YTNodes.Button ]);
Aug 25 10:56:41 volumio volumio[1057]: this.chip_bar = Reflect.has(data, 'chipBar') ? Parser.parseItem(data.chipBar, [ YTNodes.ChipCloud ]) : undefined;
Aug 25 10:56:41 volumio volumio[1057]: }
Aug 25 10:56:41 volumio volumio[1057]: }
Aug 25 10:56:41 volumio volumio[1057]: info: All search sources collected, pushing search results
Aug 25 10:56:41 volumio volumio[1057]: info: explodeTIDALUri took 289 milliseconds
Aug 25 10:56:41 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:41 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:41 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:41 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:41 volumio volumio[1057]: info: All search sources collected, pushing search results
Aug 25 10:56:42 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Aug 25 10:56:42 volumio volumio[1057]: info: CURURI: playlists/Sade
Aug 25 10:56:42 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:44 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::volumioReplaceandPlayItems
Aug 25 10:56:44 volumio volumio[1057]: info: CoreStateMachine::ClearQueue
Aug 25 10:56:44 volumio volumio[1057]: info: CoreStateMachine::stop
Aug 25 10:56:44 volumio volumio[1057]: info: CoreStateMachine::setConsumeUpdateService undefined
Aug 25 10:56:44 volumio volumio[1057]: info: CorePlayQueue::clearPlayQueue
Aug 25 10:56:44 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:44 volumio volumio[1057]: info: CoreStateMachine::addQueueItems
Aug 25 10:56:44 volumio volumio[1057]: info: CorePlayQueue::addQueueItems
Aug 25 10:56:44 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:44 volumio volumio[1057]: info: Adding Item to queue: tidal://song/149575765
Aug 25 10:56:44 volumio volumio[1057]: info: Using cached record of: tidal://song/149575765
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:44 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:44 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:44 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::volumioPlay
Aug 25 10:56:44 volumio volumio[1057]: info: CoreStateMachine::play index 0
Aug 25 10:56:44 volumio volumio[1057]: info: CoreStateMachine::setConsumeUpdateService undefined
Aug 25 10:56:44 volumio volumio[1057]: info: CoreStateMachine::stop
Aug 25 10:56:44 volumio volumio[1057]: info: CoreStateMachine::setConsumeUpdateService undefined
Aug 25 10:56:44 volumio volumio[1057]: info: CoreStateMachine::play index undefined
Aug 25 10:56:44 volumio volumio[1057]: info: CoreStateMachine::setConsumeUpdateService undefined
Aug 25 10:56:44 volumio volumio[1057]: info: CorePlayQueue::getTrack 0
Aug 25 10:56:44 volumio volumio[1057]: info: CoreStateMachine::startPlaybackTimer
Aug 25 10:56:44 volumio volumio[1057]: info: CorePlayQueue::getTrack 0
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::volumioGetVisibleSources
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Aug 25 10:56:44 volumio volumio[1057]: info: METAVOLUMIO: Retrieving similar tracks from metavolumio
Aug 25 10:56:44 volumio volumio[1057]: info: [1724576204580] ControllerTidal::clearAddPlayTrack
Aug 25 10:56:44 volumio volumio[1057]: info: Getting stream with soundQuality HIGHEST_POSSIBLE
Aug 25 10:56:44 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand stop
Aug 25 10:56:44 volumio volumio[1057]: info:
Aug 25 10:56:44 volumio volumio[1057]: ---------------------------- MPD announces state update: player
Aug 25 10:56:44 volumio volumio[1057]: info: sendMpdCommand stop took 117 milliseconds
Aug 25 10:56:44 volumio volumio[1057]: info: ControllerMpd::getState
Aug 25 10:56:44 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status
Aug 25 10:56:44 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand clear
Aug 25 10:56:44 volumio volumio[1057]: info:
Aug 25 10:56:44 volumio volumio[1057]: ---------------------------- MPD announces system playlist update
Aug 25 10:56:44 volumio volumio[1057]: info: Ignoring MPD Status Update
Aug 25 10:56:44 volumio volumio[1057]: info: sendMpdCommand status took 19 milliseconds
Aug 25 10:56:44 volumio volumio[1057]: info: sendMpdCommand clear took 19 milliseconds
Aug 25 10:56:44 volumio volumio[1057]: verbose: ControllerMpd::parseState
Aug 25 10:56:44 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 25 10:56:44 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/149575765&soundQuality=HIGHEST_POSSIBLE"
Aug 25 10:56:44 volumio volumio[1057]: error: updateQueue error: null
Aug 25 10:56:44 volumio volumio[1057]: info:
Aug 25 10:56:44 volumio volumio[1057]: ---------------------------- MPD announces system playlist update
Aug 25 10:56:44 volumio volumio[1057]: info: Ignoring MPD Status Update
Aug 25 10:56:44 volumio volumio[1057]: info: ------------------------------ 37ms
Aug 25 10:56:44 volumio volumio[1057]: info: sendMpdCommand playlistinfo took 36 milliseconds
Aug 25 10:56:44 volumio volumio[1057]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/149575765&soundQuality=HIGHEST_POSSIBLE" took 36 milliseconds
Aug 25 10:56:44 volumio volumio[1057]: verbose: ControllerMpd::parseTrackInfo
Aug 25 10:56:44 volumio volumio[1057]: info: CoreStateMachine::setConsumeUpdateService mpd
Aug 25 10:56:44 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand play
Aug 25 10:56:44 volumio volumio[1057]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined
Aug 25 10:56:44 volumio volumio[1057]: info: ------------------------------ 59ms
Aug 25 10:56:44 volumio volumio[1057]: STREAMING PROXY: Handling url /?data=tidal://song/149575765&soundQuality=HIGHEST_POSSIBLE
Aug 25 10:56:44 volumio volumio[1057]: info: ------------------------------ 41ms
Aug 25 10:56:44 volumio volumio[1057]: info: sendMpdCommand play took 40 milliseconds
Aug 25 10:56:44 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , search
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: youtube2 , search
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: spop , search
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: tidal , search
Aug 25 10:56:44 volumio volumio[1057]: info: Executing endpoint getStreamUrltidal
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI
Aug 25 10:56:44 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::volumioGetQueue
Aug 25 10:56:44 volumio volumio[1057]: info: CoreStateMachine::getQueue
Aug 25 10:56:44 volumio volumio[1057]: info: CorePlayQueue::getQueue
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::volumioAddQueueItems
Aug 25 10:56:44 volumio volumio[1057]: info: CoreStateMachine::addQueueItems
Aug 25 10:56:44 volumio volumio[1057]: info: CorePlayQueue::addQueueItems
Aug 25 10:56:44 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:44 volumio volumio[1057]: info: Adding Item to queue: spotify:track:1oaaSrDJimABpOdCEbw2DJ
Aug 25 10:56:44 volumio volumio[1057]: info: Using cached record of: spotify:track:1oaaSrDJimABpOdCEbw2DJ
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:44 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:44 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:44 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:44 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::volumioGetQueue
Aug 25 10:56:44 volumio volumio[1057]: info: CoreStateMachine::getQueue
Aug 25 10:56:44 volumio volumio[1057]: info: CorePlayQueue::getQueue
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::volumioAddQueueItems
Aug 25 10:56:44 volumio volumio[1057]: info: CoreStateMachine::addQueueItems
Aug 25 10:56:44 volumio volumio[1057]: info: CorePlayQueue::addQueueItems
Aug 25 10:56:44 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:44 volumio volumio[1057]: info: Adding Item to queue: spotify:track:7H3ojI1BsVy0dEJENqMt1k
Aug 25 10:56:44 volumio volumio[1057]: info: Using cached record of: spotify:track:7H3ojI1BsVy0dEJENqMt1k
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:44 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:44 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:44 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:44 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , search
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: youtube2 , search
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: spop , search
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: tidal , search
Aug 25 10:56:44 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , search
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: youtube2 , search
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: spop , search
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: tidal , search
Aug 25 10:56:44 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , search
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: youtube2 , search
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: spop , search
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: tidal , search
Aug 25 10:56:44 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , search
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: youtube2 , search
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: spop , search
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: tidal , search
Aug 25 10:56:44 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::volumioGetQueue
Aug 25 10:56:44 volumio volumio[1057]: info: CoreStateMachine::getQueue
Aug 25 10:56:44 volumio volumio[1057]: info: CorePlayQueue::getQueue
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::volumioAddQueueItems
Aug 25 10:56:44 volumio volumio[1057]: info: CoreStateMachine::addQueueItems
Aug 25 10:56:44 volumio volumio[1057]: info: CorePlayQueue::addQueueItems
Aug 25 10:56:44 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:44 volumio volumio[1057]: info: Adding Item to queue: spotify:track:0bgsj8kz5zWbQ6njk2Oqoz
Aug 25 10:56:44 volumio volumio[1057]: info: Using cached record of: spotify:track:0bgsj8kz5zWbQ6njk2Oqoz
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:44 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:44 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:44 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:44 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::volumioGetQueue
Aug 25 10:56:44 volumio volumio[1057]: info: CoreStateMachine::getQueue
Aug 25 10:56:44 volumio volumio[1057]: info: CorePlayQueue::getQueue
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::volumioAddQueueItems
Aug 25 10:56:44 volumio volumio[1057]: info: CoreStateMachine::addQueueItems
Aug 25 10:56:44 volumio volumio[1057]: info: CorePlayQueue::addQueueItems
Aug 25 10:56:44 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:44 volumio volumio[1057]: info: Adding Item to queue: spotify:track:4J7s7j5ulwElPG7HaGQDXR
Aug 25 10:56:44 volumio volumio[1057]: info: Using cached record of: spotify:track:4J7s7j5ulwElPG7HaGQDXR
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:44 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:44 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:44 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:44 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , search
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: youtube2 , search
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: spop , search
Aug 25 10:56:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: tidal , search
Aug 25 10:56:45 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::volumioGetQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CoreStateMachine::getQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::getQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::volumioAddQueueItems
Aug 25 10:56:45 volumio volumio[1057]: info: CoreStateMachine::addQueueItems
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::addQueueItems
Aug 25 10:56:45 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:45 volumio volumio[1057]: info: Adding Item to queue: spotify:track:1SvET7grrtsHT0CkyJjJcZ
Aug 25 10:56:45 volumio volumio[1057]: info: Using cached record of: spotify:track:1SvET7grrtsHT0CkyJjJcZ
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:45 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::volumioGetQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CoreStateMachine::getQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::getQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::volumioAddQueueItems
Aug 25 10:56:45 volumio volumio[1057]: info: CoreStateMachine::addQueueItems
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::addQueueItems
Aug 25 10:56:45 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:45 volumio volumio[1057]: info: Adding Item to queue: spotify:track:5DYD5pUUnf3MT6LafqPqOt
Aug 25 10:56:45 volumio volumio[1057]: info: Using cached record of: spotify:track:5DYD5pUUnf3MT6LafqPqOt
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:45 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , search
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: youtube2 , search
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: spop , search
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: tidal , search
Aug 25 10:56:45 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , search
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: youtube2 , search
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: spop , search
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: tidal , search
Aug 25 10:56:45 volumio volumio[1057]: info: PARSING RESPONSE ERROR Error: Album:Error: [2@0] {} Too many arguments
Aug 25 10:56:45 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , search
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: youtube2 , search
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: spop , search
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: tidal , search
Aug 25 10:56:45 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::volumioGetQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CoreStateMachine::getQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::getQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::volumioAddQueueItems
Aug 25 10:56:45 volumio volumio[1057]: info: CoreStateMachine::addQueueItems
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::addQueueItems
Aug 25 10:56:45 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:45 volumio volumio[1057]: info: Adding Item to queue: spotify:track:22QiTJqDn1BIRSh4mkNJ5w
Aug 25 10:56:45 volumio volumio[1057]: info: Using cached record of: spotify:track:22QiTJqDn1BIRSh4mkNJ5w
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:45 volumio volumio[1057]: info: PARSING RESPONSE ERROR Error: Album:Error: [2@0] {} Too many arguments
Aug 25 10:56:45 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::volumioGetQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CoreStateMachine::getQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::getQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::volumioAddQueueItems
Aug 25 10:56:45 volumio volumio[1057]: info: CoreStateMachine::addQueueItems
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::addQueueItems
Aug 25 10:56:45 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:45 volumio volumio[1057]: info: Adding Item to queue: spotify:track:0sKfhhj6hYyJIXnTiZV9vf
Aug 25 10:56:45 volumio volumio[1057]: info: Using cached record of: spotify:track:0sKfhhj6hYyJIXnTiZV9vf
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:45 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::volumioGetQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CoreStateMachine::getQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::getQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::volumioAddQueueItems
Aug 25 10:56:45 volumio volumio[1057]: info: CoreStateMachine::addQueueItems
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::addQueueItems
Aug 25 10:56:45 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:45 volumio volumio[1057]: info: Adding Item to queue: spotify:track:7pLuEMFougkSHXrPBtNxTR
Aug 25 10:56:45 volumio volumio[1057]: info: Using cached record of: spotify:track:7pLuEMFougkSHXrPBtNxTR
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:45 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::volumioGetQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CoreStateMachine::getQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::getQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::volumioAddQueueItems
Aug 25 10:56:45 volumio volumio[1057]: info: CoreStateMachine::addQueueItems
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::addQueueItems
Aug 25 10:56:45 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:45 volumio volumio[1057]: info: Adding Item to queue: spotify:track:4tReFKumS5bcFahdXDiM1b
Aug 25 10:56:45 volumio volumio[1057]: info: Using cached record of: spotify:track:4tReFKumS5bcFahdXDiM1b
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:45 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::volumioGetQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CoreStateMachine::getQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::getQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::volumioAddQueueItems
Aug 25 10:56:45 volumio volumio[1057]: info: CoreStateMachine::addQueueItems
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::addQueueItems
Aug 25 10:56:45 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:45 volumio volumio[1057]: info: Adding Item to queue: spotify:track:7pd7fTNMtn4jRv80CSdgcq
Aug 25 10:56:45 volumio volumio[1057]: info: Using cached record of: spotify:track:7pd7fTNMtn4jRv80CSdgcq
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:45 volumio volumio[1057]: info: All cached search sources collected
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::volumioGetQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CoreStateMachine::getQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::getQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::volumioAddQueueItems
Aug 25 10:56:45 volumio volumio[1057]: info: CoreStateMachine::addQueueItems
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::addQueueItems
Aug 25 10:56:45 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:45 volumio volumio[1057]: info: Adding Item to queue: spotify:track:65krtHkaYLPr0mEbjL61UP
Aug 25 10:56:45 volumio volumio[1057]: info: Using cached record of: spotify:track:65krtHkaYLPr0mEbjL61UP
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:45 volumio volumio[1057]: info: searchTIDALUri took 327 milliseconds
Aug 25 10:56:45 volumio volumio[1057]: info: search took 328 milliseconds
Aug 25 10:56:45 volumio volumio[1057]: info: getStreamUrl took 424 milliseconds
Aug 25 10:56:45 volumio volumio[1057]: error: Could not get TIDAL Stream URL
Aug 25 10:56:45 volumio volumio[1057]: error: Failed to retrieve real stream URL
Aug 25 10:56:45 volumio volumio[1057]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl
Aug 25 10:56:45 volumio volumio[1057]: info: searchTIDALUri took 290 milliseconds
Aug 25 10:56:45 volumio volumio[1057]: info: search took 291 milliseconds
Aug 25 10:56:45 volumio volumio[1057]: info: searchTIDALUri took 358 milliseconds
Aug 25 10:56:45 volumio volumio[1057]: info: search took 359 milliseconds
Aug 25 10:56:45 volumio volumio[1057]: error: An error occurred while searching WebapiRegularError: An error occurred while communicating with Spotify's Web API.
Aug 25 10:56:45 volumio volumio[1057]: Details: Bad request..
Aug 25 10:56:45 volumio volumio[1057]: error: Failed search in plugin spop:
Aug 25 10:56:45 volumio volumio[1057]: error: An error occurred while searching WebapiRegularError: An error occurred while communicating with Spotify's Web API.
Aug 25 10:56:45 volumio volumio[1057]: Details: Bad request..
Aug 25 10:56:45 volumio volumio[1057]: error: Failed search in plugin spop:
Aug 25 10:56:45 volumio volumio[1057]: info: searchTIDALUri took 435 milliseconds
Aug 25 10:56:45 volumio volumio[1057]: info: search took 436 milliseconds
Aug 25 10:56:45 volumio volumio[1057]: info: searchTIDALUri took 298 milliseconds
Aug 25 10:56:45 volumio volumio[1057]: info: search took 299 milliseconds
Aug 25 10:56:45 volumio volumio[1057]: info: searchTIDALUri took 476 milliseconds
Aug 25 10:56:45 volumio volumio[1057]: info: search took 476 milliseconds
Aug 25 10:56:45 volumio volumio[1057]: info: searchTIDALUri took 438 milliseconds
Aug 25 10:56:45 volumio volumio[1057]: info: search took 438 milliseconds
Aug 25 10:56:45 volumio volumio[1057]: info: All search sources collected, pushing search results
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::volumioGetQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CoreStateMachine::getQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::getQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::volumioAddQueueItems
Aug 25 10:56:45 volumio volumio[1057]: info: CoreStateMachine::addQueueItems
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::addQueueItems
Aug 25 10:56:45 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:45 volumio volumio[1057]: info: Adding Item to queue: tidal://song/149575025
Aug 25 10:56:45 volumio volumio[1057]: info: Using cached record of: tidal://song/149575025
Aug 25 10:56:45 volumio volumio[1057]: info: CoreCommandRouter::volumioPushQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::saveQueue
Aug 25 10:56:45 volumio volumio[1057]: info: CoreStateMachine::updateTrackBlock
Aug 25 10:56:45 volumio volumio[1057]: info: CorePlayQueue::getTrackBlock
Aug 25 10:56:45 volumio volumio[1057]: info: searchTIDALUri took 1045 milliseconds
Aug 25 10:56:45 volumio volumio[1057]: info: search took 1045 milliseconds
Aug 25 10:56:45 volumio volumio[1057]: info: All search sources collected, pushing search results
Aug 25 10:56:45 volumio volumio[1057]: info: All search sources collected, pushing search results
Aug 25 10:56:45 volumio volumio[1057]: info: searchTIDALUri took 891 milliseconds
Aug 25 10:56:45 volumio volumio[1057]: info: search took 891 milliseconds
Aug 25 10:56:46 volumio volumio[1057]: info: All search sources collected, pushing search results
Aug 25 10:56:46 volumio volumio[1057]: info: All search sources collected, pushing search results
Aug 25 10:56:46 volumio volumio[1057]: info: All search sources collected, pushing search results
Aug 25 10:56:46 volumio volumio[1057]: SearchHeader changed!
Aug 25 10:56:46 volumio volumio[1057]: The following keys where altered: chip_bar
Aug 25 10:56:46 volumio volumio[1057]: The class has changed to:
Aug 25 10:56:46 volumio volumio[1057]: class SearchHeader extends YTNode {
Aug 25 10:56:46 volumio volumio[1057]: static type = 'SearchHeader';
Aug 25 10:56:46 volumio volumio[1057]: search_filter_button: YTNodes.Button | null;
Aug 25 10:56:46 volumio volumio[1057]: chip_bar?: YTNodes.ChipCloud | null;
Aug 25 10:56:46 volumio volumio[1057]: constructor(data: RawNode) {
Aug 25 10:56:46 volumio volumio[1057]: super();
Aug 25 10:56:46 volumio volumio[1057]: this.search_filter_button = Parser.parseItem(data.searchFilterButton, [ YTNodes.Button ]);
Aug 25 10:56:46 volumio volumio[1057]: this.chip_bar = Reflect.has(data, 'chipBar') ? Parser.parseItem(data.chipBar, [ YTNodes.ChipCloud ]) : undefined;
Aug 25 10:56:46 volumio volumio[1057]: }
Aug 25 10:56:46 volumio volumio[1057]: }
Aug 25 10:56:46 volumio volumio[1057]: info: All search sources collected, pushing search results
Aug 25 10:56:46 volumio volumio[1057]: info: All search sources collected, pushing search results
Aug 25 10:56:46 volumio volumio[1057]: SearchHeader changed!
Aug 25 10:56:46 volumio volumio[1057]: The following keys where altered: chip_bar
Aug 25 10:56:46 volumio volumio[1057]: The class has changed to:
Aug 25 10:56:46 volumio volumio[1057]: class SearchHeader extends YTNode {
Aug 25 10:56:46 volumio volumio[1057]: static type = 'SearchHeader';
Aug 25 10:56:46 volumio volumio[1057]: search_filter_button: YTNodes.Button | null;
Aug 25 10:56:46 volumio volumio[1057]: chip_bar?: YTNodes.ChipCloud | null;
Aug 25 10:56:46 volumio volumio[1057]: constructor(data: RawNode) {
Aug 25 10:56:46 volumio volumio[1057]: super();
Aug 25 10:56:46 volumio volumio[1057]: this.search_filter_button = Parser.parseItem(data.searchFilterButton, [ YTNodes.Button ]);
Aug 25 10:56:46 volumio volumio[1057]: this.chip_bar = Reflect.has(data, 'chipBar') ? Parser.parseItem(data.chipBar, [ YTNodes.ChipCloud ]) : undefined;
Aug 25 10:56:46 volumio volumio[1057]: }
Aug 25 10:56:46 volumio volumio[1057]: }
Aug 25 10:56:46 volumio volumio[1057]: info: All search sources collected, pushing search results
Aug 25 10:56:46 volumio volumio[1057]: info: METAVOLUMIO: Infinity Playback added 13 Tracks to queue
Aug 25 10:56:48 volumio volumio[1057]: info: CoreCommandRouter::volumioPlay
Aug 25 10:56:48 volumio volumio[1057]: info: CoreStateMachine::play index undefined
Aug 25 10:56:48 volumio volumio[1057]: info: CoreStateMachine::setConsumeUpdateService undefined
Aug 25 10:56:48 volumio volumio[1057]: info: CorePlayQueue::getTrack 0
Aug 25 10:56:48 volumio volumio[1057]: info: CoreStateMachine::startPlaybackTimer
Aug 25 10:56:48 volumio volumio[1057]: info: CorePlayQueue::getTrack 0
Aug 25 10:56:48 volumio volumio[1057]: info: [1724576208531] ControllerTidal::clearAddPlayTrack
Aug 25 10:56:48 volumio volumio[1057]: info: Getting stream with soundQuality HIGHEST_POSSIBLE
Aug 25 10:56:48 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand stop
Aug 25 10:56:48 volumio volumio[1057]: info:
Aug 25 10:56:48 volumio volumio[1057]: ---------------------------- MPD announces state update: player
Aug 25 10:56:48 volumio volumio[1057]: info: sendMpdCommand stop took 2 milliseconds
Aug 25 10:56:48 volumio volumio[1057]: info: ControllerMpd::getState
Aug 25 10:56:48 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status
Aug 25 10:56:48 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand clear
Aug 25 10:56:48 volumio volumio[1057]: info:
Aug 25 10:56:48 volumio volumio[1057]: ---------------------------- MPD announces system playlist update
Aug 25 10:56:48 volumio volumio[1057]: info: Ignoring MPD Status Update
Aug 25 10:56:48 volumio volumio[1057]: info: sendMpdCommand status took 1 milliseconds
Aug 25 10:56:48 volumio volumio[1057]: info: sendMpdCommand clear took 2 milliseconds
Aug 25 10:56:48 volumio volumio[1057]: verbose: ControllerMpd::parseState
Aug 25 10:56:48 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Aug 25 10:56:48 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/149575765&soundQuality=HIGHEST_POSSIBLE"
Aug 25 10:56:48 volumio volumio[1057]: error: updateQueue error: null
Aug 25 10:56:48 volumio volumio[1057]: info:
Aug 25 10:56:48 volumio volumio[1057]: ---------------------------- MPD announces system playlist update
Aug 25 10:56:48 volumio volumio[1057]: info: Ignoring MPD Status Update
Aug 25 10:56:48 volumio volumio[1057]: info: ------------------------------ 5ms
Aug 25 10:56:48 volumio volumio[1057]: info: sendMpdCommand playlistinfo took 2 milliseconds
Aug 25 10:56:48 volumio volumio[1057]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/149575765&soundQuality=HIGHEST_POSSIBLE" took 2 milliseconds
Aug 25 10:56:48 volumio volumio[1057]: verbose: ControllerMpd::parseTrackInfo
Aug 25 10:56:48 volumio volumio[1057]: info: CoreStateMachine::setConsumeUpdateService mpd
Aug 25 10:56:48 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand play
Aug 25 10:56:48 volumio volumio[1057]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined
Aug 25 10:56:48 volumio volumio[1057]: info: ------------------------------ 9ms
Aug 25 10:56:48 volumio volumio[1057]: info: ------------------------------ 4ms
Aug 25 10:56:48 volumio volumio[1057]: info: sendMpdCommand play took 2 milliseconds
Aug 25 10:56:48 volumio volumio[1057]: STREAMING PROXY: Handling url /?data=tidal://song/149575765&soundQuality=HIGHEST_POSSIBLE
Aug 25 10:56:48 volumio volumio[1057]: info: Executing endpoint getStreamUrltidal
Aug 25 10:56:48 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI
Aug 25 10:56:49 volumio volumio[1057]: info: getStreamUrl took 729 milliseconds
Aug 25 10:56:49 volumio volumio[1057]: error: Could not get TIDAL Stream URL
Aug 25 10:56:49 volumio volumio[1057]: error: Failed to retrieve real stream URL
Aug 25 10:56:49 volumio volumio[1057]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl
Aug 25 10:56:50 volumio volumio[1057]: error: Search in plugin tidal timed out
Aug 25 10:56:50 volumio volumio[1057]: info: All search sources collected, pushing search results
Aug 25 10:56:50 volumio volumio[1057]: info: METAVOLUMIO: Infinity Playback added 13 Tracks to queue
Aug 25 10:56:53 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:56:59 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Aug 25 10:56:59 volumio volumio[1057]: info: CURURI: music-library
Aug 25 10:56:59 volumio volumio[1057]: error: Failed LSINFO: null
Aug 25 10:56:59 volumio volumio[1057]: info: Preload queue cleared
Aug 25 10:57:03 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Aug 25 10:57:03 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Aug 25 10:57:03 volumio volumio[1057]: info: Discovery: Getting this device information
Aug 25 10:57:03 volumio volumio[1057]: info: CoreCommandRouter::volumioGetState
Aug 25 10:57:03 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Aug 25 10:57:11 volumio ntpd[779]: Soliciting pool server 2001:41d0:700:49bc::
Aug 25 10:57:14 volumio volumio[1057]: info: CoreCommandRouter::getUIConfigOnPlugin
Aug 25 10:57:14 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Aug 25 10:57:14 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Aug 25 10:57:14 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Aug 25 10:57:14 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs
Aug 25 10:57:14 volumio volumio[1057]: info: Received Get System Version
Aug 25 10:57:14 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Aug 25 10:57:21 volumio volumio-remote-updater[645]: No test mode
Aug 25 10:57:21 volumio volumio-remote-updater[645]: No alpha test mode
Aug 25 10:57:21 volumio volumio[1057]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false}
Aug 25 10:57:21 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Aug 25 10:57:23 volumio volumio[1057]: info: CoreCommandRouter::Close All Modals sent
Aug 25 10:57:28 volumio volumio-remote-updater[645]: No test mode
Aug 25 10:57:28 volumio volumio-remote-updater[645]: No alpha test mode
Aug 25 10:57:28 volumio volumio[1057]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false}
Aug 25 10:57:28 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Aug 25 10:57:29 volumio volumio[1057]: info: CoreCommandRouter::Close All Modals sent
Aug 25 10:57:30 volumio volumio-remote-updater[645]: No test mode
Aug 25 10:57:30 volumio volumio-remote-updater[645]: No alpha test mode
Aug 25 10:57:30 volumio volumio[1057]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false}
Aug 25 10:57:30 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Aug 25 10:57:32 volumio volumio[1057]: info: CoreCommandRouter::Close All Modals sent
Aug 25 10:57:33 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Aug 25 10:57:33 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Aug 25 10:57:33 volumio volumio[1057]: info: Discovery: Getting this device information
Aug 25 10:57:33 volumio volumio[1057]: info: CoreCommandRouter::volumioGetState
Aug 25 10:57:33 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Aug 25 10:57:44 volumio volumio[1057]: info: CoreCommandRouter::getUIConfigOnPlugin
Aug 25 10:57:44 volumio volumio[1057]: info: CoreCommandRouter::getUIConfigOnPlugin
Aug 25 10:57:44 volumio volumio[1057]: info: Retrieving Cloud Streaming UI
Aug 25 10:57:44 volumio volumio[1057]: info: Getting Tidal Cloud Configuration
Aug 25 10:57:44 volumio volumio[1057]: info: CoreCommandRouter::getUIConfigOnPlugin
Aug 25 10:57:44 volumio volumio[1057]: info: Getting Qobuz Cloud Configuration
Aug 25 10:57:44 volumio volumio[1057]: info: Asking plugin for UI Config
Aug 25 10:57:44 volumio volumio[1057]: info: CoreCommandRouter::getUIConfigOnPlugin
Aug 25 10:57:44 volumio volumio[1057]: info: Getting Spotify Cloud Configuration
Aug 25 10:57:44 volumio volumio[1057]: info: Asking plugin for UI Config
Aug 25 10:57:44 volumio volumio[1057]: info: CoreCommandRouter::getUIConfigOnPlugin
Aug 25 10:57:44 volumio volumio[1057]: info: Saving Spotify Acccount
Aug 25 10:57:44 volumio volumio[1057]: info: Got it
Aug 25 10:57:44 volumio volumio[1057]: error: Could not retrieve Spotify Config from plugin Spotify: no section found
Aug 25 10:57:44 volumio volumio[1057]: info: Got Tidal Cloud Configuration
Aug 25 10:57:44 volumio volumio[1057]: info: Got it
Aug 25 10:57:44 volumio volumio[1057]: info: CoreCommandRouter::getUIConfigOnPlugin
Aug 25 10:57:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus
Aug 25 10:57:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam
Aug 25 10:57:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam
Aug 25 10:57:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam
Aug 25 10:57:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Aug 25 10:57:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Aug 25 10:57:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Aug 25 10:57:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Aug 25 10:57:44 volumio volumio[1057]: info: CoreCommandRouter::volumioGetBrowseSources
Aug 25 10:57:44 volumio volumio[1057]: info: CoreCommandRouter::volumioGetBrowseSources
Aug 25 10:57:44 volumio volumio[1057]: info: CoreCommandRouter::volumioGetBrowseSources
Aug 25 10:57:44 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Aug 25 10:57:45 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares
Aug 25 10:57:48 volumio volumio[1057]: info: Disabling MyMusic plugin upnp
Aug 25 10:57:48 volumio sudo[1874]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service
Aug 25 10:57:48 volumio sudo[1874]: pam_unix(sudo:session): session opened for user root by (uid=0)
Aug 25 10:57:48 volumio systemd[1]: Stopping UPnP Renderer front-end to MPD...
Aug 25 10:57:48 volumio volumio[1057]: error: Upnp client error: Error: This socket has been ended by the other party
Aug 25 10:57:48 volumio volumio[1057]: ------------------------------------ BT MESSAGE: BT STATUS: running
Aug 25 10:57:48 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Aug 25 10:57:52 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Aug 25 10:57:55 volumio volumio[1057]: info: Enabling MyMusic plugin upnp
Aug 25 10:57:55 volumio volumio[1057]: info: Enabling plugin upnp
Aug 25 10:57:55 volumio volumio[1057]: info: Loading plugin "upnp"...
Aug 25 10:57:55 volumio volumio[1057]: info: [1724576275103] Starting Upmpd Daemon
Aug 25 10:57:55 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Aug 25 10:57:55 volumio volumio[1057]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Aug 25 10:57:55 volumio volumio[1057]: Error: listen EADDRINUSE: address already in use :::6599
Aug 25 10:57:55 volumio volumio[1057]: at Server.setupListenHandle [as _listen2] (net.js:1318:16)
Aug 25 10:57:55 volumio volumio[1057]: at listenInCluster (net.js:1366:12)
Aug 25 10:57:55 volumio volumio[1057]: at Server.listen (net.js:1452:7)
Aug 25 10:57:55 volumio volumio[1057]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17)
Aug 25 10:57:55 volumio volumio[1057]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38)
Aug 25 10:57:55 volumio volumio[1057]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19)
Aug 25 10:57:55 volumio volumio[1057]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28)
Aug 25 10:57:55 volumio volumio[1057]: at processTicksAndRejections (internal/process/task_queues.js:75:11) {
Aug 25 10:57:55 volumio volumio[1057]: code: 'EADDRINUSE',
Aug 25 10:57:55 volumio volumio[1057]: errno: -98,
Aug 25 10:57:55 volumio volumio[1057]: syscall: 'listen',
Aug 25 10:57:55 volumio volumio[1057]: address: '::',
Aug 25 10:57:55 volumio volumio[1057]: port: 6599
Aug 25 10:57:55 volumio volumio[1057]: }
Aug 25 10:57:55 volumio volumio[1057]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Aug 25 10:57:55 volumio sudo[1886]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-08-25 10:56
Aug 25 10:57:55 volumio sudo[1886]: pam_unix(sudo:session): session opened for user root by (uid=0)
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
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="5fd3886148e72a9cecd88a772d1f6079fb64d11a"
VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6"
VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a"
VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 07:17:01 PM CEST"
VOLUMIO_VERSION="3.742"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="2782e52360f70dfab079c82951ebbbb1"