-- Logs begin at Wed 2025-02-19 19:02:06 +07, end at Thu 2025-02-20 01:06:09 +07. -- Feb 20 01:05:00 volumio volumio[976]: info: searchTIDALUri took 1750 milliseconds Feb 20 01:05:00 volumio volumio[976]: info: search took 1750 milliseconds Feb 20 01:05:00 volumio volumio[976]: info: All search sources collected, pushing search results Feb 20 01:05:03 volumio volumio[976]: Searching plugin music_service/tidal Feb 20 01:05:03 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: tidal , search Feb 20 01:05:03 volumio volumio[976]: info: searchTIDALUri took 522 milliseconds Feb 20 01:05:03 volumio volumio[976]: info: search took 523 milliseconds Feb 20 01:05:03 volumio volumio[976]: info: All search sources collected, pushing search results Feb 20 01:05:06 volumio volumio[976]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 20 01:05:06 volumio volumio[976]: info: CoreStateMachine::ClearQueue Feb 20 01:05:06 volumio volumio[976]: info: CoreStateMachine::stop Feb 20 01:05:06 volumio volumio[976]: info: CoreStateMachine::serviceStop Feb 20 01:05:06 volumio volumio[976]: info: CoreCommandRouter::serviceStop Feb 20 01:05:06 volumio volumio[976]: info: CorePlayQueue::clearPlayQueue Feb 20 01:05:06 volumio volumio[976]: info: CorePlayQueue::saveQueue Feb 20 01:05:06 volumio volumio[976]: info: CoreCommandRouter::volumioPushQueue Feb 20 01:05:06 volumio vtcs[2105]: [2025-02-20 01:05:06.243] [tisoc] [warning] [PlaybackControllerImpl.cpp:510] Illegal state:0 Feb 20 01:05:06 volumio volumio[976]: info: CoreStateMachine::addQueueItems Feb 20 01:05:06 volumio volumio[976]: info: CorePlayQueue::addQueueItems Feb 20 01:05:06 volumio volumio[976]: info: Preload queue cleared Feb 20 01:05:06 volumio volumio[976]: info: Adding Item to queue: tidal://song/291799236 Feb 20 01:05:06 volumio volumio[976]: info: Exploding uri tidal://song/291799236 in service tidal Feb 20 01:05:06 volumio volumio[976]: info: PlaybackInactive Feb 20 01:05:06 volumio volumio[976]: info: Device Session is_active: true Feb 20 01:05:06 volumio volumio[976]: info: DeviceInactive Feb 20 01:05:06 volumio volumio[976]: info: Relinquishing Volumio State Feb 20 01:05:06 volumio volumio[976]: verbose: UNSET VOLATILE: Service: tidalconnect Feb 20 01:05:06 volumio volumio[976]: info: unSetVolatile called Feb 20 01:05:06 volumio volumio[976]: info: Relinquishing Volumio State to another service Feb 20 01:05:06 volumio volumio[976]: info: CoreCommandRouter::servicePushState Feb 20 01:05:06 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:06 volumio vtcs[2105]: [2025-02-20 01:05:06.246] [tisoc] [warning] [SessionManagerImpl.cpp:243] Illegal State: IDLE Feb 20 01:05:06 volumio volumio[976]: verbose: STATE SERVICE {"status":"play","service":"tidalconnect","title":"อย่าเสียใจคนเดียว","artist":"Better Weather","album":"Run for Better Future Pt. 1","albumart":"https://resources.tidal.com/images/c01800dc/ae6a/4cbb/aefa/87b8477a046a/1280x1280.jpg","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"flac","seek":0,"duration":226,"samplerate":"96 KHz","bitdepth":"24 bit","bitrate":4608000,"channels":2,"random":false,"repeat":false,"repeatSingle":false,"stream":false,"repeatMode":"all"} Feb 20 01:05:06 volumio volumio[976]: verbose: CURRENT POSITION 0 Feb 20 01:05:06 volumio volumio[976]: info: CoreStateMachine::syncState stateService play Feb 20 01:05:06 volumio volumio[976]: info: CoreStateMachine::syncState currentStatus play Feb 20 01:05:06 volumio volumio[976]: info: Received an update from plugin. extracting info from payload Feb 20 01:05:06 volumio volumio[976]: info: CoreStateMachine::pushState Feb 20 01:05:06 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:06 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 20 01:05:06 volumio volumio[976]: info: CoreCommandRouter::volumioPushState Feb 20 01:05:06 volumio volumio[976]: info: MRS: Pushing multiroomSync output update for this device Feb 20 01:05:06 volumio volumio[976]: info: MRS: Pushing multiroomSync output Feb 20 01:05:06 volumio volumio[976]: info: CoreStateMachine::pushState Feb 20 01:05:06 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:06 volumio volumio[976]: info: CoreCommandRouter::volumioPushState Feb 20 01:05:06 volumio volumio[976]: info: MRS: Pushing multiroomSync output update for this device Feb 20 01:05:06 volumio volumio[976]: info: MRS: Pushing multiroomSync output Feb 20 01:05:06 volumio vtcs[2105]: [2025-02-20 01:05:06] [info] asio async_shutdown error: asio.misc:2 (End of file) Feb 20 01:05:06 volumio volumio[976]: info: explodeTIDALUri took 444 milliseconds Feb 20 01:05:06 volumio volumio[976]: info: CoreCommandRouter::volumioPushQueue Feb 20 01:05:06 volumio volumio[976]: info: CorePlayQueue::saveQueue Feb 20 01:05:06 volumio volumio[976]: info: CoreStateMachine::updateTrackBlock Feb 20 01:05:06 volumio volumio[976]: info: CorePlayQueue::getTrackBlock Feb 20 01:05:06 volumio volumio[976]: info: CoreCommandRouter::volumioPlay Feb 20 01:05:06 volumio volumio[976]: info: CoreStateMachine::play index 0 Feb 20 01:05:06 volumio volumio[976]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 20 01:05:06 volumio volumio[976]: info: CoreStateMachine::stop Feb 20 01:05:06 volumio volumio[976]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 20 01:05:06 volumio volumio[976]: info: CoreStateMachine::stPlaybackTimer Feb 20 01:05:06 volumio volumio[976]: info: CoreStateMachine::updateTrackBlock Feb 20 01:05:06 volumio volumio[976]: info: CorePlayQueue::getTrackBlock Feb 20 01:05:06 volumio volumio[976]: info: CoreStateMachine::pushState Feb 20 01:05:06 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:06 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 20 01:05:06 volumio volumio[976]: info: CoreCommandRouter::volumioPushState Feb 20 01:05:06 volumio volumio[976]: info: MRS: Pushing multiroomSync output update for this device Feb 20 01:05:06 volumio volumio[976]: info: MRS: Pushing multiroomSync output Feb 20 01:05:06 volumio volumio[976]: info: CoreStateMachine::serviceStop Feb 20 01:05:06 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:06 volumio volumio[976]: info: CoreCommandRouter::serviceStop Feb 20 01:05:06 volumio volumio[976]: info: [1739988306692] ControllerTidal::stop Feb 20 01:05:06 volumio volumio[976]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 20 01:05:06 volumio volumio[976]: info: ControllerMpd::stop Feb 20 01:05:06 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand stop Feb 20 01:05:06 volumio volumio[976]: info: sendMpdCommand stop took 3 milliseconds Feb 20 01:05:06 volumio volumio[976]: info: CoreStateMachine::play index undefined Feb 20 01:05:06 volumio volumio[976]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 20 01:05:06 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:06 volumio volumio[976]: info: CoreStateMachine::startPlaybackTimer Feb 20 01:05:06 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:06 volumio volumio[976]: info: CoreCommandRouter::volumioGetVisibleSources Feb 20 01:05:06 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 20 01:05:06 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 20 01:05:06 volumio volumio[976]: info: [1739988306698] ControllerTidal::clearAddPlayTrack Feb 20 01:05:06 volumio volumio[976]: info: Getting stream with soundQuality HI_RES Feb 20 01:05:06 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand stop Feb 20 01:05:06 volumio volumio[976]: info: sendMpdCommand stop took 0 milliseconds Feb 20 01:05:06 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand clear Feb 20 01:05:06 volumio volumio[976]: info: Feb 20 01:05:06 volumio volumio[976]: ---------------------------- MPD announces system playlist update Feb 20 01:05:06 volumio volumio[976]: info: Ignoring MPD Status Update Feb 20 01:05:06 volumio volumio[976]: info: sendMpdCommand clear took 0 milliseconds Feb 20 01:05:06 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/291799236&soundQuality=HI_RES" Feb 20 01:05:06 volumio volumio[976]: info: Feb 20 01:05:06 volumio volumio[976]: ---------------------------- MPD announces system playlist update Feb 20 01:05:06 volumio volumio[976]: info: Ignoring MPD Status Update Feb 20 01:05:06 volumio volumio[976]: info: Feb 20 01:05:06 volumio volumio[976]: ---------------------------- MPD announces system playlist update Feb 20 01:05:06 volumio volumio[976]: info: Ignoring MPD Status Update Feb 20 01:05:06 volumio volumio[976]: error: updateQueue error: null Feb 20 01:05:06 volumio volumio[976]: info: ------------------------------ 2ms Feb 20 01:05:06 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 20 01:05:06 volumio volumio[976]: info: [now-playing] Fetch metadata (DefaultMetadataProvider): {"type":"song","name":"อย่าเสียใจคนเดียว","artist":"Better Weather","album":"Run for Better Future Pt. 1","duration":"226","uri":"tidal://song/291799236","service":""} Feb 20 01:05:06 volumio volumio[976]: info: [now-playing] LRCLIB getLyrics(): song: "อย่าเสียใจคนเดียว" album: "Run for Better Future Pt. 1" artist: "Better Weather" duration: "226" Feb 20 01:05:06 volumio volumio[976]: info: [now-playing] LRCLIB getLyrics() API URL: https://lrclib.net/api/get?track_name=%E0%B8%AD%E0%B8%A2%E0%B9%88%E0%B8%B2%E0%B9%80%E0%B8%AA%E0%B8%B5%E0%B8%A2%E0%B9%83%E0%B8%88%E0%B8%84%E0%B8%99%E0%B9%80%E0%B8%94%E0%B8%B5%E0%B8%A2%E0%B8%A7&artist_name=Better+Weather&album_name=Run+for+Better+Future+Pt.+1&duration=226 Feb 20 01:05:06 volumio volumio[976]: info: Feb 20 01:05:06 volumio volumio[976]: ---------------------------- MPD announces system playlist update Feb 20 01:05:06 volumio volumio[976]: info: Ignoring MPD Status Update Feb 20 01:05:06 volumio volumio[976]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/291799236&soundQuality=HI_RES" took 192 milliseconds Feb 20 01:05:06 volumio volumio[976]: info: ------------------------------ 192ms Feb 20 01:05:06 volumio volumio[976]: info: ------------------------------ 191ms Feb 20 01:05:06 volumio volumio[976]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 20 01:05:06 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand play Feb 20 01:05:06 volumio volumio[976]: info: ------------------------------ 1ms Feb 20 01:05:06 volumio volumio[976]: info: Feb 20 01:05:06 volumio volumio[976]: ---------------------------- MPD announces system playlist update Feb 20 01:05:06 volumio volumio[976]: info: Ignoring MPD Status Update Feb 20 01:05:06 volumio volumio[976]: info: Feb 20 01:05:06 volumio volumio[976]: ---------------------------- MPD announces system playlist update Feb 20 01:05:06 volumio volumio[976]: info: Ignoring MPD Status Update Feb 20 01:05:06 volumio volumio[976]: info: sendMpdCommand play took 1 milliseconds Feb 20 01:05:06 volumio volumio[976]: info: ------------------------------ 0ms Feb 20 01:05:06 volumio volumio[976]: info: ------------------------------ 0ms Feb 20 01:05:06 volumio volumio[976]: STREAMING PROXY: Handling url /?data=tidal://song/291799236&soundQuality=HI_RES Feb 20 01:05:06 volumio volumio[976]: info: Executing endpoint getStreamUrltidal Feb 20 01:05:06 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Feb 20 01:05:07 volumio volumio[976]: info: getStreamUrl took 472 milliseconds Feb 20 01:05:07 volumio volumio[976]: STREAMING PROXY: Got real url: http://sp-pr-cf.audio.tidal.com/mediatracks/CAEaKwgDEidiOGQ4OGU3OWMyOGJhMjcwYWJlZmU4OWUzMzQ4Y2Q1ZV82Mi5tcDQ/0.flac?Expires=1739991907&Signature=cakuTYOlETV47Nnk8n3zhGY8Lo-DhrOmCSs5YS8OOgk4XrRDHmjTh7GzH0Wh6zxTe3wM4KIdP~KbwlQFZcl26KXCsPNWtKBhIyX~kfFIpgek4A3I5yFIyu7zBE3UkwOhNKw~ggbNHQH-T7GDnbwZYA9lvkcG6NWh6MAZWUShkCaHnMqZ~t3j1AGJKgVmOzFh25l4esVRbZt0LKcPCuB-shlja0Z5btSYROWqiahg2WBkErXv8NgqjNG0fzpUNCoaJASXgeAG9zZm62JFgIYGpckXmoPxOneTO4xe9phAjncr1px69KDDpcsGRgnpwg8h9hcS0Y3rbn1l1FhQ7uNTTA__&Key-Pair-Id=K14LZCZ9QUI4JL Feb 20 01:05:08 volumio volumio[976]: STREAMING PROXY: Response: 200, length: 65559040 Feb 20 01:05:08 volumio volumio[976]: info: Feb 20 01:05:08 volumio volumio[976]: ---------------------------- MPD announces state update: player Feb 20 01:05:08 volumio volumio[976]: info: ControllerMpd::getState Feb 20 01:05:08 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand status Feb 20 01:05:08 volumio volumio[976]: info: Feb 20 01:05:08 volumio volumio[976]: ---------------------------- MPD announces state update: player Feb 20 01:05:08 volumio volumio[976]: info: ControllerMpd::getState Feb 20 01:05:08 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand status Feb 20 01:05:08 volumio volumio[976]: info: Feb 20 01:05:08 volumio volumio[976]: ---------------------------- MPD announces state update: player Feb 20 01:05:08 volumio volumio[976]: info: ControllerMpd::getState Feb 20 01:05:08 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand status Feb 20 01:05:08 volumio volumio[976]: info: Feb 20 01:05:08 volumio volumio[976]: ---------------------------- MPD announces state update: player Feb 20 01:05:08 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand clearerror Feb 20 01:05:08 volumio volumio[976]: info: sendMpdCommand status took 45 milliseconds Feb 20 01:05:08 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand clearerror Feb 20 01:05:08 volumio volumio[976]: info: sendMpdCommand status took 45 milliseconds Feb 20 01:05:08 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand clearerror Feb 20 01:05:08 volumio volumio[976]: info: sendMpdCommand status took 46 milliseconds Feb 20 01:05:08 volumio volumio[976]: info: ControllerMpd::getState Feb 20 01:05:08 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand status Feb 20 01:05:08 volumio volumio[976]: verbose: ControllerMpd::parseState Feb 20 01:05:08 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 20 01:05:08 volumio volumio[976]: verbose: ControllerMpd::parseState Feb 20 01:05:08 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 20 01:05:08 volumio volumio[976]: verbose: ControllerMpd::parseState Feb 20 01:05:08 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 20 01:05:08 volumio volumio[976]: info: sendMpdCommand clearerror took 3 milliseconds Feb 20 01:05:08 volumio volumio[976]: info: sendMpdCommand clearerror took 3 milliseconds Feb 20 01:05:08 volumio volumio[976]: info: sendMpdCommand clearerror took 2 milliseconds Feb 20 01:05:08 volumio volumio[976]: info: sendMpdCommand status took 2 milliseconds Feb 20 01:05:08 volumio volumio[976]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 20 01:05:08 volumio volumio[976]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 20 01:05:08 volumio volumio[976]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 20 01:05:08 volumio volumio[976]: verbose: ControllerMpd::parseState Feb 20 01:05:08 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 20 01:05:08 volumio volumio[976]: verbose: ControllerMpd::parseTrackInfo Feb 20 01:05:08 volumio volumio[976]: verbose: ControllerMpd::parseTrackInfo Feb 20 01:05:08 volumio volumio[976]: verbose: ControllerMpd::parseTrackInfo Feb 20 01:05:08 volumio volumio[976]: info: ControllerMpd::pushState Feb 20 01:05:08 volumio volumio[976]: info: CoreCommandRouter::servicePushState Feb 20 01:05:08 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:08 volumio volumio[976]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":226,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"291799236&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/291799236&soundQuality=HI_RES","trackType":"tidal"} Feb 20 01:05:08 volumio volumio[976]: verbose: CURRENT POSITION 0 Feb 20 01:05:08 volumio volumio[976]: info: CoreStateMachine::syncState stateService pause Feb 20 01:05:08 volumio volumio[976]: info: CoreStateMachine::syncState currentStatus stop Feb 20 01:05:08 volumio volumio[976]: info: CoreStateMachine::pushState Feb 20 01:05:08 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 20 01:05:08 volumio volumio[976]: info: CoreCommandRouter::volumioPushState Feb 20 01:05:08 volumio volumio[976]: info: MRS: Pushing multiroomSync output update for this device Feb 20 01:05:08 volumio volumio[976]: info: MRS: Pushing multiroomSync output Feb 20 01:05:08 volumio volumio[976]: info: ControllerMpd::pushState Feb 20 01:05:08 volumio volumio[976]: info: CoreCommandRouter::servicePushState Feb 20 01:05:08 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:08 volumio volumio[976]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":226,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"291799236&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/291799236&soundQuality=HI_RES","trackType":"tidal"} Feb 20 01:05:08 volumio volumio[976]: verbose: CURRENT POSITION 0 Feb 20 01:05:08 volumio volumio[976]: info: CoreStateMachine::syncState stateService pause Feb 20 01:05:08 volumio volumio[976]: info: CoreStateMachine::syncState currentStatus stop Feb 20 01:05:08 volumio volumio[976]: info: CoreStateMachine::pushState Feb 20 01:05:08 volumio volumio[976]: info: CoreCommandRouter::volumioPushState Feb 20 01:05:08 volumio volumio[976]: info: MRS: Pushing multiroomSync output update for this device Feb 20 01:05:08 volumio volumio[976]: info: MRS: Pushing multiroomSync output Feb 20 01:05:08 volumio volumio[976]: info: ControllerMpd::pushState Feb 20 01:05:08 volumio volumio[976]: info: CoreCommandRouter::servicePushState Feb 20 01:05:08 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:08 volumio volumio[976]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":226,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"291799236&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/291799236&soundQuality=HI_RES","trackType":"tidal"} Feb 20 01:05:08 volumio volumio[976]: verbose: CURRENT POSITION 0 Feb 20 01:05:08 volumio volumio[976]: info: CoreStateMachine::syncState stateService pause Feb 20 01:05:08 volumio volumio[976]: info: CoreStateMachine::syncState currentStatus stop Feb 20 01:05:08 volumio volumio[976]: info: CoreStateMachine::pushState Feb 20 01:05:08 volumio volumio[976]: info: CoreCommandRouter::volumioPushState Feb 20 01:05:08 volumio volumio[976]: info: MRS: Pushing multiroomSync output update for this device Feb 20 01:05:08 volumio volumio[976]: info: MRS: Pushing multiroomSync output Feb 20 01:05:08 volumio volumio[976]: info: ------------------------------ 59ms Feb 20 01:05:08 volumio volumio[976]: info: ------------------------------ 58ms Feb 20 01:05:08 volumio volumio[976]: info: Feb 20 01:05:08 volumio volumio[976]: ---------------------------- MPD announces state update: player Feb 20 01:05:08 volumio volumio[976]: info: ControllerMpd::getState Feb 20 01:05:08 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand status Feb 20 01:05:08 volumio volumio[976]: info: Feb 20 01:05:08 volumio volumio[976]: ---------------------------- MPD announces state update: player Feb 20 01:05:08 volumio volumio[976]: info: ControllerMpd::getState Feb 20 01:05:08 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand status Feb 20 01:05:08 volumio volumio[976]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.7c6SlqWgvXdTlh0WCwVMmawTrbt1.11acfdbab90fdf141bfd513c3b8cfc41.state.status' Feb 20 01:05:08 volumio volumio[976]: info: sendMpdCommand playlistinfo took 14 milliseconds Feb 20 01:05:08 volumio volumio[976]: info: sendMpdCommand status took 4 milliseconds Feb 20 01:05:08 volumio volumio[976]: info: sendMpdCommand status took 3 milliseconds Feb 20 01:05:08 volumio volumio[976]: verbose: ControllerMpd::parseTrackInfo Feb 20 01:05:08 volumio volumio[976]: verbose: ControllerMpd::parseState Feb 20 01:05:08 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 20 01:05:08 volumio volumio[976]: verbose: ControllerMpd::parseState Feb 20 01:05:08 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 20 01:05:08 volumio volumio[976]: info: ControllerMpd::pushState Feb 20 01:05:08 volumio volumio[976]: info: CoreCommandRouter::servicePushState Feb 20 01:05:08 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:08 volumio volumio[976]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":226,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"291799236&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/291799236&soundQuality=HI_RES","trackType":"tidal"} Feb 20 01:05:08 volumio volumio[976]: verbose: CURRENT POSITION 0 Feb 20 01:05:08 volumio volumio[976]: info: CoreStateMachine::syncState stateService pause Feb 20 01:05:08 volumio volumio[976]: info: CoreStateMachine::syncState currentStatus stop Feb 20 01:05:08 volumio volumio[976]: info: CoreStateMachine::pushState Feb 20 01:05:08 volumio volumio[976]: info: CoreCommandRouter::volumioPushState Feb 20 01:05:08 volumio volumio[976]: info: MRS: Pushing multiroomSync output update for this device Feb 20 01:05:08 volumio volumio[976]: info: MRS: Pushing multiroomSync output Feb 20 01:05:08 volumio volumio[976]: info: ------------------------------ 21ms Feb 20 01:05:08 volumio volumio[976]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 20 01:05:08 volumio volumio[976]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 20 01:05:08 volumio volumio[976]: verbose: ControllerMpd::parseTrackInfo Feb 20 01:05:08 volumio volumio[976]: verbose: ControllerMpd::parseTrackInfo Feb 20 01:05:08 volumio volumio[976]: info: ControllerMpd::pushState Feb 20 01:05:08 volumio volumio[976]: info: CoreCommandRouter::servicePushState Feb 20 01:05:08 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:08 volumio volumio[976]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":226,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"291799236&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/291799236&soundQuality=HI_RES","trackType":"tidal"} Feb 20 01:05:08 volumio volumio[976]: verbose: CURRENT POSITION 0 Feb 20 01:05:08 volumio volumio[976]: info: CoreStateMachine::syncState stateService pause Feb 20 01:05:08 volumio volumio[976]: info: CoreStateMachine::syncState currentStatus stop Feb 20 01:05:08 volumio volumio[976]: info: CoreStateMachine::pushState Feb 20 01:05:08 volumio volumio[976]: info: CoreCommandRouter::volumioPushState Feb 20 01:05:08 volumio volumio[976]: info: MRS: Pushing multiroomSync output update for this device Feb 20 01:05:08 volumio volumio[976]: info: MRS: Pushing multiroomSync output Feb 20 01:05:08 volumio volumio[976]: info: ControllerMpd::pushState Feb 20 01:05:08 volumio volumio[976]: info: CoreCommandRouter::servicePushState Feb 20 01:05:08 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:08 volumio volumio[976]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":226,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"291799236&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/291799236&soundQuality=HI_RES","trackType":"tidal"} Feb 20 01:05:08 volumio volumio[976]: verbose: CURRENT POSITION 0 Feb 20 01:05:08 volumio volumio[976]: info: CoreStateMachine::syncState stateService pause Feb 20 01:05:08 volumio volumio[976]: info: CoreStateMachine::syncState currentStatus stop Feb 20 01:05:08 volumio volumio[976]: info: CoreStateMachine::pushState Feb 20 01:05:08 volumio volumio[976]: info: CoreCommandRouter::volumioPushState Feb 20 01:05:08 volumio volumio[976]: info: MRS: Pushing multiroomSync output update for this device Feb 20 01:05:08 volumio volumio[976]: info: MRS: Pushing multiroomSync output Feb 20 01:05:08 volumio volumio[976]: info: ------------------------------ 12ms Feb 20 01:05:08 volumio volumio[976]: info: ------------------------------ 12ms Feb 20 01:05:08 volumio volumio[976]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.7c6SlqWgvXdTlh0WCwVMmawTrbt1.11acfdbab90fdf141bfd513c3b8cfc41.state.status' Feb 20 01:05:08 volumio volumio[976]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.7c6SlqWgvXdTlh0WCwVMmawTrbt1.11acfdbab90fdf141bfd513c3b8cfc41.state.status' Feb 20 01:05:08 volumio volumio[976]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.7c6SlqWgvXdTlh0WCwVMmawTrbt1.11acfdbab90fdf141bfd513c3b8cfc41.state.status' Feb 20 01:05:12 volumio volumio[976]: STREAMING PROXY: Client dropped request, destroying Feb 20 01:05:13 volumio volumio[976]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::ClearQueue Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::stop Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 20 01:05:13 volumio volumio[976]: info: CorePlayQueue::clearPlayQueue Feb 20 01:05:13 volumio volumio[976]: info: CorePlayQueue::saveQueue Feb 20 01:05:13 volumio volumio[976]: info: CoreCommandRouter::volumioPushQueue Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::addQueueItems Feb 20 01:05:13 volumio volumio[976]: info: CorePlayQueue::addQueueItems Feb 20 01:05:13 volumio volumio[976]: info: Preload queue cleared Feb 20 01:05:13 volumio volumio[976]: info: Adding Item to queue: tidal://song/291799236 Feb 20 01:05:13 volumio volumio[976]: info: Using cached record of: tidal://song/291799236 Feb 20 01:05:13 volumio volumio[976]: info: CoreCommandRouter::volumioPushQueue Feb 20 01:05:13 volumio volumio[976]: info: CorePlayQueue::saveQueue Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::updateTrackBlock Feb 20 01:05:13 volumio volumio[976]: info: CorePlayQueue::getTrackBlock Feb 20 01:05:13 volumio volumio[976]: info: CoreCommandRouter::volumioPlay Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::play index 0 Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::stop Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::play index undefined Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 20 01:05:13 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::startPlaybackTimer Feb 20 01:05:13 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:13 volumio volumio[976]: info: CoreCommandRouter::volumioGetVisibleSources Feb 20 01:05:13 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 20 01:05:13 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 20 01:05:13 volumio volumio[976]: info: [1739988313476] ControllerTidal::clearAddPlayTrack Feb 20 01:05:13 volumio volumio[976]: info: Getting stream with soundQuality HI_RES Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand stop Feb 20 01:05:13 volumio volumio[976]: info: Feb 20 01:05:13 volumio volumio[976]: ---------------------------- MPD announces state update: player Feb 20 01:05:13 volumio volumio[976]: info: sendMpdCommand stop took 3 milliseconds Feb 20 01:05:13 volumio volumio[976]: info: ControllerMpd::getState Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand status Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand clear Feb 20 01:05:13 volumio volumio[976]: info: Feb 20 01:05:13 volumio volumio[976]: ---------------------------- MPD announces state update: player Feb 20 01:05:13 volumio volumio[976]: info: ControllerMpd::getState Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand status Feb 20 01:05:13 volumio volumio[976]: info: Feb 20 01:05:13 volumio volumio[976]: ---------------------------- MPD announces state update: player Feb 20 01:05:13 volumio volumio[976]: info: ControllerMpd::getState Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand status Feb 20 01:05:13 volumio volumio[976]: info: Feb 20 01:05:13 volumio volumio[976]: ---------------------------- MPD announces system playlist update Feb 20 01:05:13 volumio volumio[976]: info: Ignoring MPD Status Update Feb 20 01:05:13 volumio volumio[976]: info: sendMpdCommand status took 1 milliseconds Feb 20 01:05:13 volumio volumio[976]: info: sendMpdCommand clear took 1 milliseconds Feb 20 01:05:13 volumio volumio[976]: info: sendMpdCommand status took 1 milliseconds Feb 20 01:05:13 volumio volumio[976]: info: sendMpdCommand status took 1 milliseconds Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::parseState Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/291799236&soundQuality=HI_RES" Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::parseState Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::parseState Feb 20 01:05:13 volumio volumio[976]: info: ControllerMpd::pushState Feb 20 01:05:13 volumio volumio[976]: info: CoreCommandRouter::servicePushState Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::pushState Feb 20 01:05:13 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:13 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 20 01:05:13 volumio volumio[976]: info: CoreCommandRouter::volumioPushState Feb 20 01:05:13 volumio volumio[976]: info: MRS: Pushing multiroomSync output update for this device Feb 20 01:05:13 volumio volumio[976]: info: MRS: Pushing multiroomSync output Feb 20 01:05:13 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:13 volumio volumio[976]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd Feb 20 01:05:13 volumio volumio[976]: info: ControllerMpd::pushState Feb 20 01:05:13 volumio volumio[976]: info: CoreCommandRouter::servicePushState Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::pushState Feb 20 01:05:13 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:13 volumio volumio[976]: info: CoreCommandRouter::volumioPushState Feb 20 01:05:13 volumio volumio[976]: info: MRS: Pushing multiroomSync output update for this device Feb 20 01:05:13 volumio volumio[976]: info: MRS: Pushing multiroomSync output Feb 20 01:05:13 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:13 volumio volumio[976]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd Feb 20 01:05:13 volumio volumio[976]: info: ------------------------------ 6ms Feb 20 01:05:13 volumio volumio[976]: info: ------------------------------ 6ms Feb 20 01:05:13 volumio volumio[976]: info: Feb 20 01:05:13 volumio volumio[976]: ---------------------------- MPD announces system playlist update Feb 20 01:05:13 volumio volumio[976]: info: Ignoring MPD Status Update Feb 20 01:05:13 volumio volumio[976]: info: Feb 20 01:05:13 volumio volumio[976]: ---------------------------- MPD announces system playlist update Feb 20 01:05:13 volumio volumio[976]: info: Ignoring MPD Status Update Feb 20 01:05:13 volumio volumio[976]: error: updateQueue error: null Feb 20 01:05:13 volumio volumio[976]: info: Feb 20 01:05:13 volumio volumio[976]: ---------------------------- MPD announces system playlist update Feb 20 01:05:13 volumio volumio[976]: info: Ignoring MPD Status Update Feb 20 01:05:13 volumio volumio[976]: info: ------------------------------ 6ms Feb 20 01:05:13 volumio volumio[976]: info: sendMpdCommand playlistinfo took 6 milliseconds Feb 20 01:05:13 volumio volumio[976]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/291799236&soundQuality=HI_RES" took 6 milliseconds Feb 20 01:05:13 volumio volumio[976]: info: ------------------------------ 1ms Feb 20 01:05:13 volumio volumio[976]: info: ------------------------------ 1ms Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::parseTrackInfo Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand play Feb 20 01:05:13 volumio volumio[976]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Feb 20 01:05:13 volumio volumio[976]: info: ------------------------------ 8ms Feb 20 01:05:13 volumio volumio[976]: info: Feb 20 01:05:13 volumio volumio[976]: ---------------------------- MPD announces system playlist update Feb 20 01:05:13 volumio volumio[976]: info: Ignoring MPD Status Update Feb 20 01:05:13 volumio volumio[976]: info: Feb 20 01:05:13 volumio volumio[976]: ---------------------------- MPD announces system playlist update Feb 20 01:05:13 volumio volumio[976]: info: Ignoring MPD Status Update Feb 20 01:05:13 volumio volumio[976]: STREAMING PROXY: Handling url /?data=tidal://song/291799236&soundQuality=HI_RES Feb 20 01:05:13 volumio volumio[976]: info: ------------------------------ 3ms Feb 20 01:05:13 volumio volumio[976]: info: sendMpdCommand play took 3 milliseconds Feb 20 01:05:13 volumio volumio[976]: info: ------------------------------ 2ms Feb 20 01:05:13 volumio volumio[976]: info: ------------------------------ 2ms Feb 20 01:05:13 volumio volumio[976]: info: Executing endpoint getStreamUrltidal Feb 20 01:05:13 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Feb 20 01:05:13 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 20 01:05:13 volumio volumio[976]: info: [now-playing] Fetch metadata (DefaultMetadataProvider): {"type":"song","name":"อย่าเสียใจคนเดียว","artist":"Better Weather","album":"Run for Better Future Pt. 1","duration":"226","uri":"tidal://song/291799236","service":""} Feb 20 01:05:13 volumio volumio[976]: info: getStreamUrl took 389 milliseconds Feb 20 01:05:13 volumio volumio[976]: STREAMING PROXY: Got real url: http://sp-pr-cf.audio.tidal.com/mediatracks/CAEaKwgDEidiOGQ4OGU3OWMyOGJhMjcwYWJlZmU4OWUzMzQ4Y2Q1ZV82Mi5tcDQ/0.flac?Expires=1739991907&Signature=cakuTYOlETV47Nnk8n3zhGY8Lo-DhrOmCSs5YS8OOgk4XrRDHmjTh7GzH0Wh6zxTe3wM4KIdP~KbwlQFZcl26KXCsPNWtKBhIyX~kfFIpgek4A3I5yFIyu7zBE3UkwOhNKw~ggbNHQH-T7GDnbwZYA9lvkcG6NWh6MAZWUShkCaHnMqZ~t3j1AGJKgVmOzFh25l4esVRbZt0LKcPCuB-shlja0Z5btSYROWqiahg2WBkErXv8NgqjNG0fzpUNCoaJASXgeAG9zZm62JFgIYGpckXmoPxOneTO4xe9phAjncr1px69KDDpcsGRgnpwg8h9hcS0Y3rbn1l1FhQ7uNTTA__&Key-Pair-Id=K14LZCZ9QUI4JL Feb 20 01:05:13 volumio volumio[976]: STREAMING PROXY: Response: 200, length: 65559040 Feb 20 01:05:13 volumio volumio[976]: info: Feb 20 01:05:13 volumio volumio[976]: ---------------------------- MPD announces state update: player Feb 20 01:05:13 volumio volumio[976]: info: ControllerMpd::getState Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand status Feb 20 01:05:13 volumio volumio[976]: info: Feb 20 01:05:13 volumio volumio[976]: ---------------------------- MPD announces state update: player Feb 20 01:05:13 volumio volumio[976]: info: ControllerMpd::getState Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand status Feb 20 01:05:13 volumio volumio[976]: info: Feb 20 01:05:13 volumio volumio[976]: ---------------------------- MPD announces state update: player Feb 20 01:05:13 volumio volumio[976]: info: ControllerMpd::getState Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand status Feb 20 01:05:13 volumio volumio[976]: info: Feb 20 01:05:13 volumio volumio[976]: ---------------------------- MPD announces state update: player Feb 20 01:05:13 volumio volumio[976]: info: ControllerMpd::getState Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand status Feb 20 01:05:13 volumio volumio[976]: info: Feb 20 01:05:13 volumio volumio[976]: ---------------------------- MPD announces state update: player Feb 20 01:05:13 volumio volumio[976]: info: ControllerMpd::getState Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand status Feb 20 01:05:13 volumio volumio[976]: info: Feb 20 01:05:13 volumio volumio[976]: ---------------------------- MPD announces state update: player Feb 20 01:05:13 volumio volumio[976]: info: ControllerMpd::getState Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand status Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand clearerror Feb 20 01:05:13 volumio volumio[976]: info: sendMpdCommand status took 3 milliseconds Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand clearerror Feb 20 01:05:13 volumio volumio[976]: info: sendMpdCommand status took 3 milliseconds Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand clearerror Feb 20 01:05:13 volumio volumio[976]: info: sendMpdCommand status took 3 milliseconds Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand clearerror Feb 20 01:05:13 volumio volumio[976]: info: sendMpdCommand status took 3 milliseconds Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::parseState Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::parseState Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::parseState Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::parseState Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand clearerror Feb 20 01:05:13 volumio volumio[976]: info: sendMpdCommand status took 4 milliseconds Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand clearerror Feb 20 01:05:13 volumio volumio[976]: info: sendMpdCommand status took 4 milliseconds Feb 20 01:05:13 volumio volumio[976]: info: sendMpdCommand clearerror took 3 milliseconds Feb 20 01:05:13 volumio volumio[976]: info: sendMpdCommand clearerror took 2 milliseconds Feb 20 01:05:13 volumio volumio[976]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::parseState Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::parseState Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::parseTrackInfo Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::parseTrackInfo Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::parseTrackInfo Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::parseTrackInfo Feb 20 01:05:13 volumio volumio[976]: info: ControllerMpd::pushState Feb 20 01:05:13 volumio volumio[976]: info: CoreCommandRouter::servicePushState Feb 20 01:05:13 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:13 volumio volumio[976]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":226,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"291799236&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/291799236&soundQuality=HI_RES","trackType":"tidal"} Feb 20 01:05:13 volumio volumio[976]: verbose: CURRENT POSITION 0 Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::syncState stateService pause Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::syncState currentStatus stop Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::pushState Feb 20 01:05:13 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 20 01:05:13 volumio volumio[976]: info: CoreCommandRouter::volumioPushState Feb 20 01:05:13 volumio volumio[976]: info: MRS: Pushing multiroomSync output update for this device Feb 20 01:05:13 volumio volumio[976]: info: MRS: Pushing multiroomSync output Feb 20 01:05:13 volumio volumio[976]: info: ControllerMpd::pushState Feb 20 01:05:13 volumio volumio[976]: info: CoreCommandRouter::servicePushState Feb 20 01:05:13 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:13 volumio volumio[976]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":226,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"291799236&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/291799236&soundQuality=HI_RES","trackType":"tidal"} Feb 20 01:05:13 volumio volumio[976]: verbose: CURRENT POSITION 0 Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::syncState stateService pause Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::syncState currentStatus stop Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::pushState Feb 20 01:05:13 volumio volumio[976]: info: CoreCommandRouter::volumioPushState Feb 20 01:05:13 volumio volumio[976]: info: MRS: Pushing multiroomSync output update for this device Feb 20 01:05:13 volumio volumio[976]: info: MRS: Pushing multiroomSync output Feb 20 01:05:13 volumio volumio[976]: info: ControllerMpd::pushState Feb 20 01:05:13 volumio volumio[976]: info: CoreCommandRouter::servicePushState Feb 20 01:05:13 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:13 volumio volumio[976]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":226,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"291799236&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/291799236&soundQuality=HI_RES","trackType":"tidal"} Feb 20 01:05:13 volumio volumio[976]: verbose: CURRENT POSITION 0 Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::syncState stateService pause Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::syncState currentStatus stop Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::pushState Feb 20 01:05:13 volumio volumio[976]: info: CoreCommandRouter::volumioPushState Feb 20 01:05:13 volumio volumio[976]: info: MRS: Pushing multiroomSync output update for this device Feb 20 01:05:13 volumio volumio[976]: info: MRS: Pushing multiroomSync output Feb 20 01:05:13 volumio volumio[976]: info: ControllerMpd::pushState Feb 20 01:05:13 volumio volumio[976]: info: CoreCommandRouter::servicePushState Feb 20 01:05:13 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:13 volumio volumio[976]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":226,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"291799236&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/291799236&soundQuality=HI_RES","trackType":"tidal"} Feb 20 01:05:13 volumio volumio[976]: verbose: CURRENT POSITION 0 Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::syncState stateService pause Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::syncState currentStatus stop Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::pushState Feb 20 01:05:13 volumio volumio[976]: info: CoreCommandRouter::volumioPushState Feb 20 01:05:13 volumio volumio[976]: info: MRS: Pushing multiroomSync output update for this device Feb 20 01:05:13 volumio volumio[976]: info: MRS: Pushing multiroomSync output Feb 20 01:05:13 volumio volumio[976]: info: ------------------------------ 18ms Feb 20 01:05:13 volumio volumio[976]: info: ------------------------------ 18ms Feb 20 01:05:13 volumio volumio[976]: info: ------------------------------ 18ms Feb 20 01:05:13 volumio volumio[976]: info: ------------------------------ 18ms Feb 20 01:05:13 volumio volumio[976]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.7c6SlqWgvXdTlh0WCwVMmawTrbt1.11acfdbab90fdf141bfd513c3b8cfc41.state.status' Feb 20 01:05:13 volumio volumio[976]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.7c6SlqWgvXdTlh0WCwVMmawTrbt1.11acfdbab90fdf141bfd513c3b8cfc41.state.status' Feb 20 01:05:13 volumio volumio[976]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.7c6SlqWgvXdTlh0WCwVMmawTrbt1.11acfdbab90fdf141bfd513c3b8cfc41.state.status' Feb 20 01:05:13 volumio volumio[976]: info: sendMpdCommand clearerror took 18 milliseconds Feb 20 01:05:13 volumio volumio[976]: info: sendMpdCommand clearerror took 18 milliseconds Feb 20 01:05:13 volumio volumio[976]: info: sendMpdCommand playlistinfo took 16 milliseconds Feb 20 01:05:13 volumio volumio[976]: info: sendMpdCommand playlistinfo took 16 milliseconds Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::parseTrackInfo Feb 20 01:05:13 volumio volumio[976]: verbose: ControllerMpd::parseTrackInfo Feb 20 01:05:13 volumio volumio[976]: info: ControllerMpd::pushState Feb 20 01:05:13 volumio volumio[976]: info: CoreCommandRouter::servicePushState Feb 20 01:05:13 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:13 volumio volumio[976]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":226,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"291799236&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/291799236&soundQuality=HI_RES","trackType":"tidal"} Feb 20 01:05:13 volumio volumio[976]: verbose: CURRENT POSITION 0 Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::syncState stateService pause Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::syncState currentStatus stop Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::pushState Feb 20 01:05:13 volumio volumio[976]: info: CoreCommandRouter::volumioPushState Feb 20 01:05:13 volumio volumio[976]: info: MRS: Pushing multiroomSync output update for this device Feb 20 01:05:13 volumio volumio[976]: info: MRS: Pushing multiroomSync output Feb 20 01:05:13 volumio volumio[976]: info: ControllerMpd::pushState Feb 20 01:05:13 volumio volumio[976]: info: CoreCommandRouter::servicePushState Feb 20 01:05:13 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:13 volumio volumio[976]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":226,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"291799236&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/291799236&soundQuality=HI_RES","trackType":"tidal"} Feb 20 01:05:13 volumio volumio[976]: verbose: CURRENT POSITION 0 Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::syncState stateService pause Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::syncState currentStatus stop Feb 20 01:05:13 volumio volumio[976]: info: CoreStateMachine::pushState Feb 20 01:05:13 volumio volumio[976]: info: CoreCommandRouter::volumioPushState Feb 20 01:05:13 volumio volumio[976]: info: MRS: Pushing multiroomSync output update for this device Feb 20 01:05:13 volumio volumio[976]: info: MRS: Pushing multiroomSync output Feb 20 01:05:13 volumio volumio[976]: info: ------------------------------ 30ms Feb 20 01:05:13 volumio volumio[976]: info: ------------------------------ 30ms Feb 20 01:05:13 volumio volumio[976]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.7c6SlqWgvXdTlh0WCwVMmawTrbt1.11acfdbab90fdf141bfd513c3b8cfc41.state.status' Feb 20 01:05:13 volumio volumio[976]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.7c6SlqWgvXdTlh0WCwVMmawTrbt1.11acfdbab90fdf141bfd513c3b8cfc41.state.status' Feb 20 01:05:14 volumio volumio[976]: STREAMING PROXY: Client dropped request, destroying Feb 20 01:05:21 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 20 01:05:21 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 20 01:05:21 volumio volumio[976]: info: Discovery: Getting this device information Feb 20 01:05:21 volumio volumio[976]: info: CoreCommandRouter::volumioGetState Feb 20 01:05:21 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 20 01:05:28 volumio volumio[976]: info: CoreCommandRouter::volumioClearQueue Feb 20 01:05:28 volumio volumio[976]: info: CoreStateMachine::ClearQueue Feb 20 01:05:28 volumio volumio[976]: info: CoreStateMachine::stop Feb 20 01:05:28 volumio volumio[976]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 20 01:05:28 volumio volumio[976]: info: CorePlayQueue::clearPlayQueue Feb 20 01:05:28 volumio volumio[976]: info: CorePlayQueue::saveQueue Feb 20 01:05:28 volumio volumio[976]: info: CoreCommandRouter::volumioPushState Feb 20 01:05:28 volumio volumio[976]: info: MRS: Pushing multiroomSync output update for this device Feb 20 01:05:28 volumio volumio[976]: info: MRS: Pushing multiroomSync output Feb 20 01:05:28 volumio volumio[976]: info: CoreCommandRouter::volumioPushQueue Feb 20 01:05:29 volumio volumio[976]: info: CoreCommandRouter::volumioClearQueue Feb 20 01:05:29 volumio volumio[976]: info: CoreStateMachine::ClearQueue Feb 20 01:05:29 volumio volumio[976]: info: CoreStateMachine::stop Feb 20 01:05:29 volumio volumio[976]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 20 01:05:29 volumio volumio[976]: info: CorePlayQueue::clearPlayQueue Feb 20 01:05:29 volumio volumio[976]: info: CorePlayQueue::saveQueue Feb 20 01:05:29 volumio volumio[976]: info: CoreCommandRouter::volumioPushState Feb 20 01:05:29 volumio volumio[976]: info: MRS: Pushing multiroomSync output update for this device Feb 20 01:05:29 volumio volumio[976]: info: MRS: Pushing multiroomSync output Feb 20 01:05:29 volumio volumio[976]: info: CoreCommandRouter::volumioPushQueue Feb 20 01:05:29 volumio volumio[976]: info: CoreCommandRouter::volumioClearQueue Feb 20 01:05:29 volumio volumio[976]: info: CoreStateMachine::ClearQueue Feb 20 01:05:29 volumio volumio[976]: info: CoreStateMachine::stop Feb 20 01:05:29 volumio volumio[976]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 20 01:05:29 volumio volumio[976]: info: CorePlayQueue::clearPlayQueue Feb 20 01:05:29 volumio volumio[976]: info: CorePlayQueue::saveQueue Feb 20 01:05:29 volumio volumio[976]: info: CoreCommandRouter::volumioPushState Feb 20 01:05:29 volumio volumio[976]: info: MRS: Pushing multiroomSync output update for this device Feb 20 01:05:29 volumio volumio[976]: info: MRS: Pushing multiroomSync output Feb 20 01:05:29 volumio volumio[976]: info: CoreCommandRouter::volumioPushQueue Feb 20 01:05:36 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Feb 20 01:05:36 volumio volumio[976]: info: browseTIDALUri took 174 milliseconds Feb 20 01:05:36 volumio volumio[976]: info: Preload queue cleared Feb 20 01:05:36 volumio volumio[976]: info: Preload queue cleared Feb 20 01:05:41 volumio volumio[976]: Searching plugin music_service/tidal Feb 20 01:05:41 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: tidal , search Feb 20 01:05:42 volumio volumio[976]: info: searchTIDALUri took 972 milliseconds Feb 20 01:05:42 volumio volumio[976]: info: search took 972 milliseconds Feb 20 01:05:42 volumio volumio[976]: info: All search sources collected, pushing search results Feb 20 01:05:43 volumio volumio[976]: Searching plugin music_service/tidal Feb 20 01:05:43 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: tidal , search Feb 20 01:05:44 volumio volumio[976]: info: searchTIDALUri took 1046 milliseconds Feb 20 01:05:44 volumio volumio[976]: info: search took 1046 milliseconds Feb 20 01:05:44 volumio volumio[976]: info: All search sources collected, pushing search results Feb 20 01:05:44 volumio volumio[976]: Searching plugin music_service/tidal Feb 20 01:05:44 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: tidal , search Feb 20 01:05:44 volumio volumio[976]: info: searchTIDALUri took 533 milliseconds Feb 20 01:05:44 volumio volumio[976]: info: search took 533 milliseconds Feb 20 01:05:44 volumio volumio[976]: info: All search sources collected, pushing search results Feb 20 01:05:45 volumio volumio[976]: Searching plugin music_service/tidal Feb 20 01:05:45 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: tidal , search Feb 20 01:05:45 volumio volumio[976]: info: searchTIDALUri took 226 milliseconds Feb 20 01:05:45 volumio volumio[976]: info: search took 226 milliseconds Feb 20 01:05:45 volumio volumio[976]: info: All search sources collected, pushing search results Feb 20 01:05:51 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 20 01:05:51 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 20 01:05:51 volumio volumio[976]: info: Discovery: Getting this device information Feb 20 01:05:51 volumio volumio[976]: info: CoreCommandRouter::volumioGetState Feb 20 01:05:51 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:51 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 20 01:05:52 volumio volumio[976]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 20 01:05:52 volumio volumio[976]: info: CoreStateMachine::ClearQueue Feb 20 01:05:52 volumio volumio[976]: info: CoreStateMachine::stop Feb 20 01:05:52 volumio volumio[976]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 20 01:05:52 volumio volumio[976]: info: CorePlayQueue::clearPlayQueue Feb 20 01:05:52 volumio volumio[976]: info: CorePlayQueue::saveQueue Feb 20 01:05:52 volumio volumio[976]: info: CoreCommandRouter::volumioPushQueue Feb 20 01:05:52 volumio volumio[976]: info: CoreStateMachine::addQueueItems Feb 20 01:05:52 volumio volumio[976]: info: CorePlayQueue::addQueueItems Feb 20 01:05:52 volumio volumio[976]: info: Preload queue cleared Feb 20 01:05:52 volumio volumio[976]: info: Adding Item to queue: tidal://song/291799236 Feb 20 01:05:52 volumio volumio[976]: info: Using cached record of: tidal://song/291799236 Feb 20 01:05:52 volumio volumio[976]: info: CoreCommandRouter::volumioPushQueue Feb 20 01:05:52 volumio volumio[976]: info: CorePlayQueue::saveQueue Feb 20 01:05:52 volumio volumio[976]: info: CoreStateMachine::updateTrackBlock Feb 20 01:05:52 volumio volumio[976]: info: CorePlayQueue::getTrackBlock Feb 20 01:05:52 volumio volumio[976]: info: CoreCommandRouter::volumioPlay Feb 20 01:05:52 volumio volumio[976]: info: CoreStateMachine::play index 0 Feb 20 01:05:52 volumio volumio[976]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 20 01:05:52 volumio volumio[976]: info: CoreStateMachine::stop Feb 20 01:05:52 volumio volumio[976]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 20 01:05:52 volumio volumio[976]: info: CoreStateMachine::play index undefined Feb 20 01:05:52 volumio volumio[976]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 20 01:05:52 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:52 volumio volumio[976]: info: CoreStateMachine::startPlaybackTimer Feb 20 01:05:52 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:52 volumio volumio[976]: info: CoreCommandRouter::volumioGetVisibleSources Feb 20 01:05:52 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 20 01:05:52 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 20 01:05:52 volumio volumio[976]: info: [1739988352714] ControllerTidal::clearAddPlayTrack Feb 20 01:05:52 volumio volumio[976]: info: Getting stream with soundQuality HI_RES Feb 20 01:05:52 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand stop Feb 20 01:05:52 volumio volumio[976]: info: Feb 20 01:05:52 volumio volumio[976]: ---------------------------- MPD announces state update: player Feb 20 01:05:52 volumio volumio[976]: info: sendMpdCommand stop took 2 milliseconds Feb 20 01:05:52 volumio volumio[976]: info: ControllerMpd::getState Feb 20 01:05:52 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand status Feb 20 01:05:52 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand clear Feb 20 01:05:52 volumio volumio[976]: info: Feb 20 01:05:52 volumio volumio[976]: ---------------------------- MPD announces state update: player Feb 20 01:05:52 volumio volumio[976]: info: ControllerMpd::getState Feb 20 01:05:52 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand status Feb 20 01:05:52 volumio volumio[976]: info: Feb 20 01:05:52 volumio volumio[976]: ---------------------------- MPD announces state update: player Feb 20 01:05:52 volumio volumio[976]: info: ControllerMpd::getState Feb 20 01:05:52 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand status Feb 20 01:05:52 volumio volumio[976]: info: Feb 20 01:05:52 volumio volumio[976]: ---------------------------- MPD announces system playlist update Feb 20 01:05:52 volumio volumio[976]: info: Ignoring MPD Status Update Feb 20 01:05:52 volumio volumio[976]: info: sendMpdCommand status took 1 milliseconds Feb 20 01:05:52 volumio volumio[976]: info: sendMpdCommand clear took 1 milliseconds Feb 20 01:05:52 volumio volumio[976]: info: sendMpdCommand status took 1 milliseconds Feb 20 01:05:52 volumio volumio[976]: info: sendMpdCommand status took 0 milliseconds Feb 20 01:05:52 volumio volumio[976]: verbose: ControllerMpd::parseState Feb 20 01:05:52 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 20 01:05:52 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/291799236&soundQuality=HI_RES" Feb 20 01:05:52 volumio volumio[976]: verbose: ControllerMpd::parseState Feb 20 01:05:52 volumio volumio[976]: verbose: ControllerMpd::parseState Feb 20 01:05:52 volumio volumio[976]: info: ControllerMpd::pushState Feb 20 01:05:52 volumio volumio[976]: info: CoreCommandRouter::servicePushState Feb 20 01:05:52 volumio volumio[976]: info: CoreStateMachine::pushState Feb 20 01:05:52 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:52 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 20 01:05:52 volumio volumio[976]: info: CoreCommandRouter::volumioPushState Feb 20 01:05:52 volumio volumio[976]: info: MRS: Pushing multiroomSync output update for this device Feb 20 01:05:52 volumio volumio[976]: info: MRS: Pushing multiroomSync output Feb 20 01:05:52 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:52 volumio volumio[976]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd Feb 20 01:05:52 volumio volumio[976]: info: ControllerMpd::pushState Feb 20 01:05:52 volumio volumio[976]: info: CoreCommandRouter::servicePushState Feb 20 01:05:52 volumio volumio[976]: info: CoreStateMachine::pushState Feb 20 01:05:52 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:52 volumio volumio[976]: info: CoreCommandRouter::volumioPushState Feb 20 01:05:52 volumio volumio[976]: info: MRS: Pushing multiroomSync output update for this device Feb 20 01:05:52 volumio volumio[976]: info: MRS: Pushing multiroomSync output Feb 20 01:05:52 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:52 volumio volumio[976]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd Feb 20 01:05:52 volumio volumio[976]: info: ------------------------------ 4ms Feb 20 01:05:52 volumio volumio[976]: info: ------------------------------ 5ms Feb 20 01:05:52 volumio volumio[976]: info: Feb 20 01:05:52 volumio volumio[976]: ---------------------------- MPD announces system playlist update Feb 20 01:05:52 volumio volumio[976]: info: Ignoring MPD Status Update Feb 20 01:05:52 volumio volumio[976]: info: Feb 20 01:05:52 volumio volumio[976]: ---------------------------- MPD announces system playlist update Feb 20 01:05:52 volumio volumio[976]: info: Ignoring MPD Status Update Feb 20 01:05:52 volumio volumio[976]: error: updateQueue error: null Feb 20 01:05:52 volumio volumio[976]: info: Feb 20 01:05:52 volumio volumio[976]: ---------------------------- MPD announces system playlist update Feb 20 01:05:52 volumio volumio[976]: info: Ignoring MPD Status Update Feb 20 01:05:52 volumio volumio[976]: info: ------------------------------ 4ms Feb 20 01:05:52 volumio volumio[976]: info: sendMpdCommand playlistinfo took 4 milliseconds Feb 20 01:05:52 volumio volumio[976]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/291799236&soundQuality=HI_RES" took 4 milliseconds Feb 20 01:05:52 volumio volumio[976]: info: ------------------------------ 0ms Feb 20 01:05:52 volumio volumio[976]: info: ------------------------------ 1ms Feb 20 01:05:52 volumio volumio[976]: verbose: ControllerMpd::parseTrackInfo Feb 20 01:05:52 volumio volumio[976]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 20 01:05:52 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand play Feb 20 01:05:52 volumio volumio[976]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Feb 20 01:05:52 volumio volumio[976]: info: ------------------------------ 6ms Feb 20 01:05:52 volumio volumio[976]: info: Feb 20 01:05:52 volumio volumio[976]: ---------------------------- MPD announces system playlist update Feb 20 01:05:52 volumio volumio[976]: info: Ignoring MPD Status Update Feb 20 01:05:52 volumio volumio[976]: info: Feb 20 01:05:52 volumio volumio[976]: ---------------------------- MPD announces system playlist update Feb 20 01:05:52 volumio volumio[976]: info: Ignoring MPD Status Update Feb 20 01:05:52 volumio volumio[976]: STREAMING PROXY: Handling url /?data=tidal://song/291799236&soundQuality=HI_RES Feb 20 01:05:52 volumio volumio[976]: info: ------------------------------ 5ms Feb 20 01:05:52 volumio volumio[976]: info: sendMpdCommand play took 4 milliseconds Feb 20 01:05:52 volumio volumio[976]: info: ------------------------------ 4ms Feb 20 01:05:52 volumio volumio[976]: info: Executing endpoint getStreamUrltidal Feb 20 01:05:52 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Feb 20 01:05:52 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 20 01:05:52 volumio volumio[976]: info: [now-playing] Fetch metadata (DefaultMetadataProvider): {"type":"song","name":"อย่าเสียใจคนเดียว","artist":"Better Weather","album":"Run for Better Future Pt. 1","duration":"226","uri":"tidal://song/291799236","service":""} Feb 20 01:05:53 volumio volumio[976]: info: getStreamUrl took 395 milliseconds Feb 20 01:05:53 volumio volumio[976]: STREAMING PROXY: Got real url: http://sp-pr-cf.audio.tidal.com/mediatracks/CAEaKwgDEidiOGQ4OGU3OWMyOGJhMjcwYWJlZmU4OWUzMzQ4Y2Q1ZV82Mi5tcDQ/0.flac?Expires=1739991907&Signature=cakuTYOlETV47Nnk8n3zhGY8Lo-DhrOmCSs5YS8OOgk4XrRDHmjTh7GzH0Wh6zxTe3wM4KIdP~KbwlQFZcl26KXCsPNWtKBhIyX~kfFIpgek4A3I5yFIyu7zBE3UkwOhNKw~ggbNHQH-T7GDnbwZYA9lvkcG6NWh6MAZWUShkCaHnMqZ~t3j1AGJKgVmOzFh25l4esVRbZt0LKcPCuB-shlja0Z5btSYROWqiahg2WBkErXv8NgqjNG0fzpUNCoaJASXgeAG9zZm62JFgIYGpckXmoPxOneTO4xe9phAjncr1px69KDDpcsGRgnpwg8h9hcS0Y3rbn1l1FhQ7uNTTA__&Key-Pair-Id=K14LZCZ9QUI4JL Feb 20 01:05:53 volumio volumio[976]: STREAMING PROXY: Response: 200, length: 65559040 Feb 20 01:05:53 volumio volumio[976]: info: Feb 20 01:05:53 volumio volumio[976]: ---------------------------- MPD announces state update: player Feb 20 01:05:53 volumio volumio[976]: info: ControllerMpd::getState Feb 20 01:05:53 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand status Feb 20 01:05:53 volumio volumio[976]: info: Feb 20 01:05:53 volumio volumio[976]: ---------------------------- MPD announces state update: player Feb 20 01:05:53 volumio volumio[976]: info: ControllerMpd::getState Feb 20 01:05:53 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand status Feb 20 01:05:53 volumio volumio[976]: info: Feb 20 01:05:53 volumio volumio[976]: ---------------------------- MPD announces state update: player Feb 20 01:05:53 volumio volumio[976]: info: ControllerMpd::getState Feb 20 01:05:53 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand status Feb 20 01:05:53 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand clearerror Feb 20 01:05:53 volumio volumio[976]: info: sendMpdCommand status took 2 milliseconds Feb 20 01:05:53 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand clearerror Feb 20 01:05:53 volumio volumio[976]: info: sendMpdCommand status took 1 milliseconds Feb 20 01:05:53 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand clearerror Feb 20 01:05:53 volumio volumio[976]: info: sendMpdCommand status took 3 milliseconds Feb 20 01:05:53 volumio volumio[976]: verbose: ControllerMpd::parseState Feb 20 01:05:53 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 20 01:05:53 volumio volumio[976]: verbose: ControllerMpd::parseState Feb 20 01:05:53 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 20 01:05:53 volumio volumio[976]: verbose: ControllerMpd::parseState Feb 20 01:05:53 volumio volumio[976]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 20 01:05:53 volumio volumio[976]: info: sendMpdCommand clearerror took 3 milliseconds Feb 20 01:05:53 volumio volumio[976]: info: sendMpdCommand clearerror took 4 milliseconds Feb 20 01:05:53 volumio volumio[976]: info: sendMpdCommand clearerror took 2 milliseconds Feb 20 01:05:53 volumio volumio[976]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 20 01:05:53 volumio volumio[976]: info: sendMpdCommand playlistinfo took 9 milliseconds Feb 20 01:05:53 volumio volumio[976]: verbose: ControllerMpd::parseTrackInfo Feb 20 01:05:53 volumio volumio[976]: info: ControllerMpd::pushState Feb 20 01:05:53 volumio volumio[976]: info: CoreCommandRouter::servicePushState Feb 20 01:05:53 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:53 volumio volumio[976]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":226,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"291799236&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/291799236&soundQuality=HI_RES","trackType":"tidal"} Feb 20 01:05:53 volumio volumio[976]: verbose: CURRENT POSITION 0 Feb 20 01:05:53 volumio volumio[976]: info: CoreStateMachine::syncState stateService pause Feb 20 01:05:53 volumio volumio[976]: info: CoreStateMachine::syncState currentStatus stop Feb 20 01:05:53 volumio volumio[976]: info: CoreStateMachine::pushState Feb 20 01:05:53 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 20 01:05:53 volumio volumio[976]: info: CoreCommandRouter::volumioPushState Feb 20 01:05:53 volumio volumio[976]: info: MRS: Pushing multiroomSync output update for this device Feb 20 01:05:53 volumio volumio[976]: info: MRS: Pushing multiroomSync output Feb 20 01:05:53 volumio volumio[976]: info: ControllerMpd::pushState Feb 20 01:05:53 volumio volumio[976]: info: CoreCommandRouter::servicePushState Feb 20 01:05:53 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:53 volumio volumio[976]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":226,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"291799236&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/291799236&soundQuality=HI_RES","trackType":"tidal"} Feb 20 01:05:53 volumio volumio[976]: verbose: CURRENT POSITION 0 Feb 20 01:05:53 volumio volumio[976]: info: CoreStateMachine::syncState stateService pause Feb 20 01:05:53 volumio volumio[976]: info: CoreStateMachine::syncState currentStatus stop Feb 20 01:05:53 volumio volumio[976]: info: CoreStateMachine::pushState Feb 20 01:05:53 volumio volumio[976]: info: CoreCommandRouter::volumioPushState Feb 20 01:05:53 volumio volumio[976]: info: MRS: Pushing multiroomSync output update for this device Feb 20 01:05:53 volumio volumio[976]: info: MRS: Pushing multiroomSync output Feb 20 01:05:53 volumio volumio[976]: info: ControllerMpd::pushState Feb 20 01:05:53 volumio volumio[976]: info: CoreCommandRouter::servicePushState Feb 20 01:05:53 volumio volumio[976]: info: CorePlayQueue::getTrack 0 Feb 20 01:05:53 volumio volumio[976]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":226,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"291799236&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/291799236&soundQuality=HI_RES","trackType":"tidal"} Feb 20 01:05:53 volumio volumio[976]: verbose: CURRENT POSITION 0 Feb 20 01:05:53 volumio volumio[976]: info: CoreStateMachine::syncState stateService pause Feb 20 01:05:53 volumio volumio[976]: info: CoreStateMachine::syncState currentStatus stop Feb 20 01:05:53 volumio volumio[976]: info: CoreStateMachine::pushState Feb 20 01:05:53 volumio volumio[976]: info: CoreCommandRouter::volumioPushState Feb 20 01:05:53 volumio volumio[976]: info: MRS: Pushing multiroomSync output update for this device Feb 20 01:05:53 volumio volumio[976]: info: MRS: Pushing multiroomSync output Feb 20 01:05:53 volumio volumio[976]: info: ------------------------------ 22ms Feb 20 01:05:53 volumio volumio[976]: info: ------------------------------ 22ms Feb 20 01:05:53 volumio volumio[976]: info: ------------------------------ 21ms Feb 20 01:05:53 volumio volumio[976]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.7c6SlqWgvXdTlh0WCwVMmawTrbt1.11acfdbab90fdf141bfd513c3b8cfc41.state.status' Feb 20 01:05:53 volumio volumio[976]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.7c6SlqWgvXdTlh0WCwVMmawTrbt1.11acfdbab90fdf141bfd513c3b8cfc41.state.status' Feb 20 01:05:53 volumio volumio[976]: STREAMING PROXY: Client dropped request, destroying Feb 20 01:05:59 volumio volumio[976]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 20 01:05:59 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Feb 20 01:05:59 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Feb 20 01:05:59 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Feb 20 01:05:59 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Feb 20 01:06:00 volumio volumio[976]: info: Received Get System Version Feb 20 01:06:00 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 20 01:06:04 volumio volumio[976]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 20 01:06:04 volumio volumio[976]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 20 01:06:04 volumio volumio[976]: info: Retrieving Cloud Streaming UI Feb 20 01:06:04 volumio volumio[976]: info: Getting Tidal Cloud Configuration Feb 20 01:06:04 volumio volumio[976]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 20 01:06:04 volumio volumio[976]: info: Getting Qobuz Cloud Configuration Feb 20 01:06:04 volumio volumio[976]: info: Asking plugin for UI Config Feb 20 01:06:04 volumio volumio[976]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 20 01:06:04 volumio volumio[976]: info: Getting Spotify Cloud Configuration Feb 20 01:06:04 volumio volumio[976]: info: Asking plugin for UI Config Feb 20 01:06:04 volumio volumio[976]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 20 01:06:04 volumio volumio[976]: info: Saving Spotify Acccount Feb 20 01:06:04 volumio volumio[976]: info: Got it Feb 20 01:06:04 volumio volumio[976]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Feb 20 01:06:04 volumio volumio[976]: info: Got Tidal Cloud Configuration Feb 20 01:06:04 volumio volumio[976]: info: Got it Feb 20 01:06:04 volumio volumio[976]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 20 01:06:04 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 20 01:06:04 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 20 01:06:04 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 20 01:06:04 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 20 01:06:04 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 20 01:06:04 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 20 01:06:04 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 20 01:06:04 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 20 01:06:04 volumio volumio[976]: info: CoreCommandRouter::volumioGetBrowseSources Feb 20 01:06:04 volumio volumio[976]: info: CoreCommandRouter::volumioGetBrowseSources Feb 20 01:06:04 volumio volumio[976]: info: CoreCommandRouter::volumioGetBrowseSources Feb 20 01:06:05 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 20 01:06:05 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Feb 20 01:06:06 volumio volumio[976]: info: Disabling MyMusic plugin upnp Feb 20 01:06:06 volumio sudo[4605]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Feb 20 01:06:06 volumio sudo[4605]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 01:06:07 volumio systemd[1]: Stopping UPnP Renderer front-end to MPD... Feb 20 01:06:07 volumio volumio[976]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 20 01:06:07 volumio volumio[976]: error: Upnp client error: Error: This socket has been ended by the other party Feb 20 01:06:09 volumio volumio[976]: info: Enabling MyMusic plugin upnp Feb 20 01:06:09 volumio volumio[976]: info: Enabling plugin upnp Feb 20 01:06:09 volumio volumio[976]: info: Loading plugin "upnp"... Feb 20 01:06:09 volumio volumio[976]: info: [1739988369114] Starting Upmpd Daemon Feb 20 01:06:09 volumio volumio[976]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 20 01:06:09 volumio volumio[976]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 20 01:06:09 volumio volumio[976]: Error: listen EADDRINUSE: address already in use :::6599 Feb 20 01:06:09 volumio volumio[976]: at Server.setupListenHandle [as _listen2] (net.js:1331:16) Feb 20 01:06:09 volumio volumio[976]: at listenInCluster (net.js:1379:12) Feb 20 01:06:09 volumio volumio[976]: at Server.listen (net.js:1465:7) Feb 20 01:06:09 volumio volumio[976]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Feb 20 01:06:09 volumio volumio[976]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Feb 20 01:06:09 volumio volumio[976]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Feb 20 01:06:09 volumio volumio[976]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Feb 20 01:06:09 volumio volumio[976]: at processTicksAndRejections (internal/process/task_queues.js:77:11) { Feb 20 01:06:09 volumio volumio[976]: code: 'EADDRINUSE', Feb 20 01:06:09 volumio volumio[976]: errno: -98, Feb 20 01:06:09 volumio volumio[976]: syscall: 'listen', Feb 20 01:06:09 volumio volumio[976]: address: '::', Feb 20 01:06:09 volumio volumio[976]: port: 6599 Feb 20 01:06:09 volumio volumio[976]: } Feb 20 01:06:09 volumio volumio[976]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 20 01:06:09 volumio sudo[4633]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-02-20 01:05 Feb 20 01:06:09 volumio sudo[4633]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 07:25:16 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="66c567362bdbb3dc1644a18f7879afe7"