-- Logs begin at Mon 2025-05-19 17:34:44 PST, end at Mon 2025-05-26 17:18:34 PST. -- May 26 17:17:07 rivo-streamer volumio[3124]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 26 17:17:07 rivo-streamer volumio[3124]: info: CURURI: playlists May 26 17:17:07 rivo-streamer volumio[3124]: info: Listing playlists May 26 17:17:07 rivo-streamer volumio[3124]: info: Preload queue cleared May 26 17:17:08 rivo-streamer go-librespot[3719]: time="2025-05-26T17:17:08+08:00" level=trace msg="sent dealer ping" May 26 17:17:08 rivo-streamer go-librespot[3719]: time="2025-05-26T17:17:08+08:00" level=trace msg="received dealer pong" May 26 17:17:11 rivo-streamer volumio[3124]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 26 17:17:11 rivo-streamer volumio[3124]: info: CURURI: music-library May 26 17:17:11 rivo-streamer mpd[3647]: exception: No database May 26 17:17:11 rivo-streamer volumio[3124]: error: Failed LSINFO: Error: [50@0] {lsinfo} No database May 26 17:17:11 rivo-streamer volumio[3124]: info: Preload queue cleared May 26 17:17:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 26 17:17:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 26 17:17:13 rivo-streamer volumio[3124]: info: Discovery: Getting this device information May 26 17:17:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioGetState May 26 17:17:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 26 17:17:16 rivo-streamer volumio[3124]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 26 17:17:16 rivo-streamer volumio[3124]: info: CURURI: albums:// May 26 17:17:16 rivo-streamer mpd[3647]: exception: No database May 26 17:17:16 rivo-streamer volumio[3124]: error: Failed to execute browseSource: Error: Cannot list albums May 26 17:17:19 rivo-streamer volumio[3124]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 26 17:17:19 rivo-streamer volumio[3124]: info: CURURI: artists:// May 26 17:17:19 rivo-streamer mpd[3647]: exception: No database May 26 17:17:19 rivo-streamer volumio[3124]: error: Failed to execute browseSource: Error: Cannot list artist May 26 17:17:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 26 17:17:23 rivo-streamer volumio[3124]: info: CURURI: music-library May 26 17:17:23 rivo-streamer mpd[3647]: exception: No database May 26 17:17:23 rivo-streamer volumio[3124]: error: Failed LSINFO: Error: [50@0] {lsinfo} No database May 26 17:17:23 rivo-streamer volumio[3124]: info: Preload queue cleared May 26 17:17:28 rivo-streamer volumio[3124]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 26 17:17:28 rivo-streamer volumio[3124]: info: Preload queue cleared May 26 17:17:29 rivo-streamer volumio[3124]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 26 17:17:29 rivo-streamer volumio[3124]: info: Preload queue cleared May 26 17:17:30 rivo-streamer volumio[3124]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 26 17:17:30 rivo-streamer volumio[3124]: info: Preload queue cleared May 26 17:17:35 rivo-streamer volumio[3124]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 26 17:17:35 rivo-streamer ntpd[3322]: Soliciting pool server 222.127.1.21 May 26 17:17:36 rivo-streamer volumio[3124]: info: Preload queue cleared May 26 17:17:37 rivo-streamer volumiologrotate[2839]: ls: cannot access '/var/log/samba/log.wb-RIVO': No such file or directory May 26 17:17:37 rivo-streamer ntpd[3322]: Soliciting pool server 222.127.1.20 May 26 17:17:37 rivo-streamer ntpd[3322]: Soliciting pool server 222.127.1.20 May 26 17:17:37 rivo-streamer volumiologrotate[2839]: ls: cannot access 'STREAMER': No such file or directory May 26 17:17:38 rivo-streamer ntpd[3322]: Soliciting pool server 2405:8d40:f27:cd00:3d0b:a6df:43f7:e7c9 May 26 17:17:38 rivo-streamer go-librespot[3719]: time="2025-05-26T17:17:38+08:00" level=trace msg="sent dealer ping" May 26 17:17:38 rivo-streamer go-librespot[3719]: time="2025-05-26T17:17:38+08:00" level=trace msg="received dealer pong" May 26 17:17:43 rivo-streamer volumio[3124]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 26 17:17:43 rivo-streamer volumio[3124]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 26 17:17:43 rivo-streamer volumio[3124]: info: Discovery: Getting this device information May 26 17:17:43 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioGetState May 26 17:17:43 rivo-streamer volumio[3124]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 26 17:17:48 rivo-streamer volumio[3124]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 26 17:17:48 rivo-streamer volumio[3124]: info: Preload queue cleared May 26 17:17:50 rivo-streamer volumio[3124]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 26 17:17:50 rivo-streamer volumio[3124]: info: Preload queue cleared May 26 17:17:50 rivo-streamer volumio[3124]: info: Preloading song: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22153 May 26 17:17:50 rivo-streamer volumio[3124]: info: Preloading song: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22154 May 26 17:17:50 rivo-streamer volumio[3124]: info: Preloading song: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22155 May 26 17:17:50 rivo-streamer volumio[3124]: info: Preloading song: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22156 May 26 17:17:50 rivo-streamer volumio[3124]: info: Preloading song: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22157 May 26 17:17:50 rivo-streamer volumio[3124]: info: Preloading song: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22158 May 26 17:17:50 rivo-streamer volumio[3124]: info: Preloading song: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22159 May 26 17:17:50 rivo-streamer volumio[3124]: info: Preloading song: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22160 May 26 17:17:50 rivo-streamer volumio[3124]: info: Preloading song: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22161 May 26 17:17:50 rivo-streamer volumio[3124]: info: Preloading song: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22162 May 26 17:17:50 rivo-streamer volumio[3124]: info: Preloading song: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22163 May 26 17:17:50 rivo-streamer volumio[3124]: info: Exploding uri upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22153 in service upnp_browser May 26 17:17:51 rivo-streamer volumio[3124]: info: Exploding uri upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22154 in service upnp_browser May 26 17:17:51 rivo-streamer volumio[3124]: info: Exploding uri upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22155 in service upnp_browser May 26 17:17:51 rivo-streamer volumio[3124]: info: Exploding uri upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22156 in service upnp_browser May 26 17:17:51 rivo-streamer volumio[3124]: info: Exploding uri upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22157 in service upnp_browser May 26 17:17:51 rivo-streamer volumio[3124]: info: Exploding uri upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22158 in service upnp_browser May 26 17:17:51 rivo-streamer volumio[3124]: info: Exploding uri upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22159 in service upnp_browser May 26 17:17:51 rivo-streamer volumio[3124]: info: Exploding uri upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22160 in service upnp_browser May 26 17:17:51 rivo-streamer volumio[3124]: info: Exploding uri upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22161 in service upnp_browser May 26 17:17:51 rivo-streamer volumio[3124]: info: Exploding uri upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22162 in service upnp_browser May 26 17:17:51 rivo-streamer volumio[3124]: info: Exploding uri upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22163 in service upnp_browser May 26 17:17:52 rivo-streamer volumio[3124]: info: Preload queue cleared May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioReplaceandPlayItems May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreStateMachine::ClearQueue May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreStateMachine::stop May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreStateMachine::serviceStop May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreCommandRouter::serviceStop May 26 17:17:52 rivo-streamer volumio[3124]: info: QobuzConnect: Received stop May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioGetState May 26 17:17:52 rivo-streamer qobuz-connect[3653]: 20250526 17:17:52.329 [3653.3653] INFO MediaEngine: [0xacac2ec8]: Stopping playback, keeping tracks May 26 17:17:52 rivo-streamer qobuz-connect[3653]: 20250526 17:17:52.330 [3653.3653] INFO AudioRenderer: [0xacac30e8]: Stopping audio renderer May 26 17:17:52 rivo-streamer qobuz-connect[3653]: 20250526 17:17:52.330 [3653.3653] INFO SampleApp: Stopping playback May 26 17:17:52 rivo-streamer volumio[3124]: info: CorePlayQueue::clearPlayQueue May 26 17:17:52 rivo-streamer volumio[3124]: info: CorePlayQueue::saveQueue May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushQueue May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreStateMachine::addQueueItems May 26 17:17:52 rivo-streamer volumio[3124]: info: CorePlayQueue::addQueueItems May 26 17:17:52 rivo-streamer volumio[3124]: info: Preload queue cleared May 26 17:17:52 rivo-streamer volumio[3124]: info: Adding Item to queue: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22153 May 26 17:17:52 rivo-streamer volumio[3124]: info: Using cached record of: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22153 May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushQueue May 26 17:17:52 rivo-streamer volumio[3124]: info: CorePlayQueue::saveQueue May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreStateMachine::updateTrackBlock May 26 17:17:52 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrackBlock May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPlay May 26 17:17:52 rivo-streamer volumio[3124]: verbose: UNSET VOLATILE: Service: qobuzconnect May 26 17:17:52 rivo-streamer volumio[3124]: info: QobuzConnect: onUnsetVolatile() called, relinquishing Volumio State to another service May 26 17:17:52 rivo-streamer volumio[3124]: info: QobuzConnect: Received stop May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioGetState May 26 17:17:52 rivo-streamer qobuz-connect[3653]: 20250526 17:17:52.354 [3653.3653] INFO AudioStreamManager: [0xacac2fb0]: Clearing all streams May 26 17:17:52 rivo-streamer qobuz-connect[3653]: 20250526 17:17:52.354 [3653.3653] INFO AudioStreamManager: [0xacac2fb0]: [Stream 2]: Disposing of audio stream May 26 17:17:52 rivo-streamer qobuz-connect[3653]: 20250526 17:17:52.354 [3653.3653] INFO ContentFetcher: [0xaccdc4c0]: Canceling download May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreStateMachine::play index 0 May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreStateMachine::addQueueItems May 26 17:17:52 rivo-streamer volumio[3124]: info: CorePlayQueue::addQueueItems May 26 17:17:52 rivo-streamer volumio[3124]: info: Preload queue cleared May 26 17:17:52 rivo-streamer volumio[3124]: info: Adding Item to queue: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22154 May 26 17:17:52 rivo-streamer volumio[3124]: info: Using cached record of: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22154 May 26 17:17:52 rivo-streamer volumio[3124]: info: Adding Item to queue: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22155 May 26 17:17:52 rivo-streamer volumio[3124]: info: Using cached record of: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22155 May 26 17:17:52 rivo-streamer volumio[3124]: info: Adding Item to queue: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22156 May 26 17:17:52 rivo-streamer volumio[3124]: info: Using cached record of: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22156 May 26 17:17:52 rivo-streamer volumio[3124]: info: Adding Item to queue: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22157 May 26 17:17:52 rivo-streamer volumio[3124]: info: Using cached record of: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22157 May 26 17:17:52 rivo-streamer volumio[3124]: info: Adding Item to queue: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22158 May 26 17:17:52 rivo-streamer volumio[3124]: info: Using cached record of: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22158 May 26 17:17:52 rivo-streamer volumio[3124]: info: Adding Item to queue: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22159 May 26 17:17:52 rivo-streamer volumio[3124]: info: Using cached record of: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22159 May 26 17:17:52 rivo-streamer volumio[3124]: info: Adding Item to queue: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22160 May 26 17:17:52 rivo-streamer qobuz-connect[3653]: 20250526 17:17:52.362 [3653.3653] INFO AudioStreamManager: [0xacac2fb0]: New stream: 4 May 26 17:17:52 rivo-streamer qobuz-connect[3653]: 20250526 17:17:52.362 [3653.3653] INFO HttpDownloader: [0xacba8940]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=b7c83553a8632546736a457c0ed5bfb1&request_ts=1748251072&track_id=21710978 May 26 17:17:52 rivo-streamer qobuz-connect[3653]: 20250526 17:17:52.363 [3653.3653] INFO HttpDownloader: [0xacbb3f88]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=21710978 May 26 17:17:52 rivo-streamer qobuz-connect[3653]: 20250526 17:17:52.363 [3653.3653] INFO HttpDownloader: [0xacac8b68]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=85fab88cd721c16e053a8a7478730993&request_ts=1748251072&track_id=21710978 May 26 17:17:52 rivo-streamer volumio[3124]: info: Using cached record of: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22160 May 26 17:17:52 rivo-streamer volumio[3124]: info: Adding Item to queue: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22161 May 26 17:17:52 rivo-streamer volumio[3124]: info: Using cached record of: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22161 May 26 17:17:52 rivo-streamer qobuz-connect[3653]: 20250526 17:17:52.363 [3653.3653] INFO AudioStreamManager: [0xacac2fb0]: [Stream 4]: Running audio stream May 26 17:17:52 rivo-streamer qobuz-connect[3653]: 20250526 17:17:52.363 [3653.3653] INFO AudioStreamManager: [0xacac2fb0]: New stream: 5 May 26 17:17:52 rivo-streamer qobuz-connect[3653]: 20250526 17:17:52.363 [3653.3653] INFO HttpDownloader: [0xacbb4f08]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/getFileUrl?format_id=27&request_sig=e49cec5ff87cabccf3c9abb27462c591&request_ts=1748251072&track_id=28365056 May 26 17:17:52 rivo-streamer qobuz-connect[3653]: 20250526 17:17:52.363 [3653.3653] INFO HttpDownloader: [0xacb9cb40]: Downloading content from: https://www.qobuz.com/api.json/0.2/track/get?track_id=28365056 May 26 17:17:52 rivo-streamer qobuz-connect[3653]: 20250526 17:17:52.364 [3653.3653] INFO HttpDownloader: [0xacba6de8]: Downloading content from: https://www.qobuz.com/api.json/0.2/file/url?format_id=27&intent=stream&request_sig=76fd0a71f94926978b6b1290dc36e1fb&request_ts=1748251072&track_id=28365056 May 26 17:17:52 rivo-streamer qobuz-connect[3653]: 20250526 17:17:52.364 [3653.3653] INFO MediaEngine: [0xacac2ec8]: Stopping playback, keeping tracks May 26 17:17:52 rivo-streamer volumio[3124]: info: Adding Item to queue: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22162 May 26 17:17:52 rivo-streamer volumio[3124]: info: Using cached record of: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22162 May 26 17:17:52 rivo-streamer volumio[3124]: info: Adding Item to queue: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22163 May 26 17:17:52 rivo-streamer volumio[3124]: info: Using cached record of: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22163 May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreStateMachine::stop May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreStateMachine::updateTrackBlock May 26 17:17:52 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrackBlock May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreStateMachine::stPlaybackTimer May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreStateMachine::pushState May 26 17:17:52 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrack 0 May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushState May 26 17:17:52 rivo-streamer qobuz-connect[3653]: 20250526 17:17:52.373 [3653.3653] INFO SampleApp: Playback state changed: Stopped May 26 17:17:52 rivo-streamer qobuz-connect[3653]: 20250526 17:17:52.374 [3653.3653] INFO ProtocolHandler: [0xacac3608]: Need to send state update May 26 17:17:52 rivo-streamer qobuz-connect[3653]: 20250526 17:17:52.374 [3653.3653] INFO QConnectMessageSender: [0xacc081b0]: Sending StateUpdated message May 26 17:17:52 rivo-streamer qobuz-connect[3653]: 20250526 17:17:52.374 [3653.3653] INFO SampleApp: [Stream 2]: Audio stream has been disposed of May 26 17:17:52 rivo-streamer qobuz-connect[3653]: 20250526 17:17:52.374 [3653.3653] INFO QwspMessageSender: [0xacac95c8]: Sending Payload message May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioGetState May 26 17:17:52 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrack 0 May 26 17:17:52 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output update for this device May 26 17:17:52 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreStateMachine::serviceStop May 26 17:17:52 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrack 0 May 26 17:17:52 rivo-streamer volumio[3124]: info: ControllerMpd::stop May 26 17:17:52 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand stop May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushQueue May 26 17:17:52 rivo-streamer volumio[3124]: info: CorePlayQueue::saveQueue May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreStateMachine::updateTrackBlock May 26 17:17:52 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrackBlock May 26 17:17:52 rivo-streamer volumio[3124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 26 17:17:52 rivo-streamer volumio[3124]: info: QobuzConnect: playback_stop received, deferred solved May 26 17:17:52 rivo-streamer volumio[3124]: info: QobuzConnect: playback_stop received, deferred solved May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioGetState May 26 17:17:52 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrack 0 May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioGetState May 26 17:17:52 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrack 0 May 26 17:17:52 rivo-streamer volumio[3124]: info: sendMpdCommand stop took 39 milliseconds May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreStateMachine::play index undefined May 26 17:17:52 rivo-streamer volumio[3124]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 17:17:52 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrack 0 May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.077 [3653.3653] INFO AudioStreamManager: [0xacac2fb0]: [Stream 4]: stream information have been fetched May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.141 [3653.3653] INFO AudioStreamManager: [0xacac2fb0]: [Stream 5]: stream information have been fetched May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.141 [3653.3653] INFO AudioStreamManager: [0xacac2fb0]: [Stream 5]: Metadata became available: May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.141 [3653.3653] INFO AudioStreamManager: [0xacac2fb0]: Title: Never Be Alone May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.141 [3653.3653] INFO AudioStreamManager: [0xacac2fb0]: Artist: Shawn Mendes May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.141 [3653.3653] INFO AudioStreamManager: [0xacac2fb0]: Album: Handwritten (Revisited) May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.142 [3653.3653] INFO AudioStreamManager: [0xacac2fb0]: Album art URL: https://static.qobuz.com/images/covers/89/56/0060254765689_600.jpg May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.201 [3653.3653] INFO AudioStreamManager: [0xacac2fb0]: [Stream 4]: Metadata became available: May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.201 [3653.3653] INFO AudioStreamManager: [0xacac2fb0]: Title: Like I'm Gonna Lose You May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.201 [3653.3653] INFO AudioStreamManager: [0xacac2fb0]: Artist: Meghan Trainor May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.202 [3653.3653] INFO AudioStreamManager: [0xacac2fb0]: Album: Title May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.202 [3653.3653] INFO AudioStreamManager: [0xacac2fb0]: Album art URL: https://static.qobuz.com/images/covers/90/51/0886444905190_600.jpg May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.256 [3653.3653] INFO AudioStreamManager: [0xacac2fb0]: [Stream 4]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=3314988&eid=21710978&fmt=7&profile=raw&app_id=174516466&cid=2790759&etsp=1748254674&hmac=0_qMYG5kLLFYfH1cKeYtul9txmg May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.256 [3653.3653] INFO UrlAudioSource: [0xacac6f30]: Starting URL audio source, initial position: 0ms, URL: https://streaming-qobuz-std.akamaized.net/file?uid=3314988&eid=21710978&fmt=7&profile=raw&app_id=174516466&cid=2790759&etsp=1748254674&hmac=0_qMYG5kLLFYfH1cKeYtul9txmg May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.256 [3653.3653] INFO ContentFetcher: [0xacb26778]: Fetching content from: https://streaming-qobuz-std.akamaized.net/file?uid=3314988&eid=21710978&fmt=7&profile=raw&app_id=174516466&cid=2790759&etsp=1748254674&hmac=0_qMYG5kLLFYfH1cKeYtul9txmg, offset: 0 May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.257 [3653.3653] INFO SampleApp: [Stream 4]: New audio stream (starting from 0ms) May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.257 [3653.3653] INFO SampleApp: [Stream 4]: Stream metadata became available: May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.257 [3653.3653] INFO SampleApp: Title: Like I'm Gonna Lose You May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.257 [3653.3653] INFO SampleApp: Artist: Meghan Trainor May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.257 [3653.3653] INFO SampleApp: Album: Title May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.257 [3653.3653] INFO SampleApp: Album art URL: https://static.qobuz.com/images/covers/90/51/0886444905190_600.jpg May 26 17:17:53 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioGetState May 26 17:17:53 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrack 0 May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.355 [3653.3653] INFO AudioStreamManager: [0xacac2fb0]: [Stream 5]: track URL resolved to: https://streaming-qobuz-std.akamaized.net/file?uid=3314988&eid=28365056&fmt=7&profile=raw&app_id=174516466&cid=2790759&etsp=1748254674&hmac=fAv1VANGbaT7YikrPAvHi4uz1c0 May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.411 [3653.3653] INFO UrlAudioSource: [0xacac6f30]: Content info extracted May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.412 [3653.3653] INFO UrlAudioSource: [0xacac6f30]: Size: 44879042 May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.413 [3653.5536] INFO AudioDecoder: [0xacb6e348]: Stream info: May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.413 [3653.5536] INFO AudioDecoder: [0xacb6e348]: Total samples: 9950509 May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.414 [3653.5536] INFO AudioDecoder: [0xacb6e348]: Sample rate: 44100 May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.414 [3653.5536] INFO AudioDecoder: [0xacb6e348]: Channel count: 2 May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.415 [3653.5536] INFO AudioDecoder: [0xacb6e348]: Bits per sample: 24 May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.415 [3653.5536] INFO AudioDecoder: [0xacb6e348]: Duration: 225635 May 26 17:17:53 rivo-streamer qobuz-connect[3653]: 20250526 17:17:53.415 [3653.3653] INFO UrlAudioSource: [0xacac6f30]: Audio properties have changed May 26 17:17:53 rivo-streamer volumio[3124]: info: Preload queue cleared May 26 17:17:53 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioReplaceandPlayItems May 26 17:17:53 rivo-streamer volumio[3124]: info: CoreStateMachine::ClearQueue May 26 17:17:53 rivo-streamer volumio[3124]: info: CoreStateMachine::stop May 26 17:17:53 rivo-streamer volumio[3124]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 17:17:53 rivo-streamer volumio[3124]: info: CorePlayQueue::clearPlayQueue May 26 17:17:53 rivo-streamer volumio[3124]: info: CorePlayQueue::saveQueue May 26 17:17:53 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushQueue May 26 17:17:53 rivo-streamer volumio[3124]: info: CoreStateMachine::addQueueItems May 26 17:17:53 rivo-streamer volumio[3124]: info: CorePlayQueue::addQueueItems May 26 17:17:53 rivo-streamer volumio[3124]: info: Preload queue cleared May 26 17:17:53 rivo-streamer volumio[3124]: info: Adding Item to queue: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22153 May 26 17:17:53 rivo-streamer volumio[3124]: info: Using cached record of: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22153 May 26 17:17:53 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushQueue May 26 17:17:53 rivo-streamer volumio[3124]: info: CorePlayQueue::saveQueue May 26 17:17:53 rivo-streamer volumio[3124]: info: CoreStateMachine::updateTrackBlock May 26 17:17:53 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrackBlock May 26 17:17:53 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPlay May 26 17:17:53 rivo-streamer volumio[3124]: info: CoreStateMachine::play index 0 May 26 17:17:53 rivo-streamer volumio[3124]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 17:17:53 rivo-streamer volumio[3124]: info: CoreStateMachine::addQueueItems May 26 17:17:53 rivo-streamer volumio[3124]: info: CorePlayQueue::addQueueItems May 26 17:17:53 rivo-streamer volumio[3124]: info: Preload queue cleared May 26 17:17:53 rivo-streamer volumio[3124]: info: Adding Item to queue: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22154 May 26 17:17:53 rivo-streamer volumio[3124]: info: Using cached record of: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22154 May 26 17:17:53 rivo-streamer volumio[3124]: info: Adding Item to queue: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22155 May 26 17:17:53 rivo-streamer volumio[3124]: info: Using cached record of: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22155 May 26 17:17:53 rivo-streamer volumio[3124]: info: Adding Item to queue: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22156 May 26 17:17:53 rivo-streamer volumio[3124]: info: Using cached record of: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22156 May 26 17:17:53 rivo-streamer volumio[3124]: info: Adding Item to queue: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22157 May 26 17:17:53 rivo-streamer volumio[3124]: info: Using cached record of: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22157 May 26 17:17:53 rivo-streamer volumio[3124]: info: Adding Item to queue: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22158 May 26 17:17:53 rivo-streamer volumio[3124]: info: Using cached record of: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22158 May 26 17:17:53 rivo-streamer volumio[3124]: info: Adding Item to queue: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22159 May 26 17:17:53 rivo-streamer volumio[3124]: info: Using cached record of: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22159 May 26 17:17:53 rivo-streamer volumio[3124]: info: Adding Item to queue: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22160 May 26 17:17:53 rivo-streamer volumio[3124]: info: Using cached record of: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22160 May 26 17:17:53 rivo-streamer volumio[3124]: info: Adding Item to queue: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22161 May 26 17:17:53 rivo-streamer volumio[3124]: info: Using cached record of: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22161 May 26 17:17:53 rivo-streamer volumio[3124]: info: Adding Item to queue: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22162 May 26 17:17:53 rivo-streamer volumio[3124]: info: Using cached record of: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22162 May 26 17:17:53 rivo-streamer volumio[3124]: info: Adding Item to queue: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22163 May 26 17:17:53 rivo-streamer volumio[3124]: info: Using cached record of: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22163 May 26 17:17:53 rivo-streamer volumio[3124]: info: CoreStateMachine::stop May 26 17:17:53 rivo-streamer volumio[3124]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 17:17:53 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushQueue May 26 17:17:53 rivo-streamer volumio[3124]: info: CorePlayQueue::saveQueue May 26 17:17:53 rivo-streamer volumio[3124]: info: CoreStateMachine::play index undefined May 26 17:17:53 rivo-streamer volumio[3124]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 17:17:53 rivo-streamer volumio[3124]: info: CoreStateMachine::updateTrackBlock May 26 17:17:53 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrackBlock May 26 17:17:53 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrack 0 May 26 17:18:06 rivo-streamer volumio[3124]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Feenbrothers/Play%20Dave%20Brubeck/78ec57b2-74dd-45bb-831c-80e5cc466c2a.jpg' May 26 17:18:06 rivo-streamer volumio[3124]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Feenbrothers/Play%20Dave%20Brubeck/6817e7c4-0589-49af-9d16-604df3683ecc.jpg' May 26 17:18:06 rivo-streamer volumio[3124]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Feenbrothers/Play%20Dave%20Brubeck/6817e7c4-0589-49af-9d16-604df3683ecc.jpg' May 26 17:18:06 rivo-streamer volumio[3124]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Feenbrothers/Play%20Dave%20Brubeck/6817e7c4-0589-49af-9d16-604df3683ecc.jpg' May 26 17:18:06 rivo-streamer volumio[3124]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Feenbrothers/Play%20Dave%20Brubeck/6817e7c4-0589-49af-9d16-604df3683ecc.jpg' May 26 17:18:06 rivo-streamer volumio[3124]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Feenbrothers/Play%20Dave%20Brubeck/6817e7c4-0589-49af-9d16-604df3683ecc.jpg' May 26 17:18:07 rivo-streamer volumio[3124]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 26 17:18:08 rivo-streamer volumio[3124]: info: Preload queue cleared May 26 17:18:08 rivo-streamer go-librespot[3719]: time="2025-05-26T17:18:08+08:00" level=trace msg="received accesspoint ping" May 26 17:18:08 rivo-streamer go-librespot[3719]: time="2025-05-26T17:18:08+08:00" level=trace msg="received accesspoint pong ack" May 26 17:18:08 rivo-streamer go-librespot[3719]: time="2025-05-26T17:18:08+08:00" level=trace msg="sent dealer ping" May 26 17:18:08 rivo-streamer go-librespot[3719]: time="2025-05-26T17:18:08+08:00" level=trace msg="received dealer pong" May 26 17:18:11 rivo-streamer volumio[3124]: info: Preload queue cleared May 26 17:18:11 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioReplaceandPlayItems May 26 17:18:11 rivo-streamer volumio[3124]: info: CoreStateMachine::ClearQueue May 26 17:18:11 rivo-streamer volumio[3124]: info: CoreStateMachine::stop May 26 17:18:11 rivo-streamer volumio[3124]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 17:18:11 rivo-streamer volumio[3124]: info: CorePlayQueue::clearPlayQueue May 26 17:18:11 rivo-streamer volumio[3124]: info: CorePlayQueue::saveQueue May 26 17:18:11 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushQueue May 26 17:18:11 rivo-streamer volumio[3124]: info: CoreStateMachine::addQueueItems May 26 17:18:11 rivo-streamer volumio[3124]: info: CorePlayQueue::addQueueItems May 26 17:18:11 rivo-streamer volumio[3124]: info: Preload queue cleared May 26 17:18:11 rivo-streamer volumio[3124]: info: Adding Item to queue: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22153 May 26 17:18:11 rivo-streamer volumio[3124]: info: Using cached record of: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@22153 May 26 17:18:11 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushQueue May 26 17:18:11 rivo-streamer volumio[3124]: info: CorePlayQueue::saveQueue May 26 17:18:11 rivo-streamer volumio[3124]: info: CoreStateMachine::updateTrackBlock May 26 17:18:11 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrackBlock May 26 17:18:11 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPlay May 26 17:18:11 rivo-streamer volumio[3124]: info: CoreStateMachine::play index 0 May 26 17:18:11 rivo-streamer volumio[3124]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 17:18:11 rivo-streamer volumio[3124]: info: CoreStateMachine::stop May 26 17:18:11 rivo-streamer volumio[3124]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 17:18:11 rivo-streamer volumio[3124]: info: CoreStateMachine::play index undefined May 26 17:18:11 rivo-streamer volumio[3124]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 17:18:11 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrack 0 May 26 17:18:13 rivo-streamer volumio[3124]: info: Preload queue cleared May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioReplaceandPlayItems May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::ClearQueue May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::stop May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 17:18:13 rivo-streamer volumio[3124]: info: CorePlayQueue::clearPlayQueue May 26 17:18:13 rivo-streamer volumio[3124]: info: CorePlayQueue::saveQueue May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushQueue May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::addQueueItems May 26 17:18:13 rivo-streamer volumio[3124]: info: CorePlayQueue::addQueueItems May 26 17:18:13 rivo-streamer volumio[3124]: info: Preload queue cleared May 26 17:18:13 rivo-streamer volumio[3124]: info: Adding Item to queue: upnp/folder/http://192.168.2.13:50001/ContentDirectory/control@22$2614 May 26 17:18:13 rivo-streamer volumio[3124]: info: Exploding uri upnp/folder/http://192.168.2.13:50001/ContentDirectory/control@22$2614 in service upnp_browser May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushQueue May 26 17:18:13 rivo-streamer volumio[3124]: info: CorePlayQueue::saveQueue May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::updateTrackBlock May 26 17:18:13 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrackBlock May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPlay May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::play index 0 May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::stop May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::play index undefined May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 17:18:13 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrack 0 May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::startPlaybackTimer May 26 17:18:13 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrack 0 May 26 17:18:13 rivo-streamer volumio[3124]: info: [1748251093614] ControllerUPNPBrowser::clearAddPlayTrack May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand stop May 26 17:18:13 rivo-streamer volumio[3124]: info: sendMpdCommand stop took 6 milliseconds May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand clear May 26 17:18:13 rivo-streamer volumio[3124]: info: May 26 17:18:13 rivo-streamer volumio[3124]: ---------------------------- MPD announces system playlist update May 26 17:18:13 rivo-streamer volumio[3124]: info: Ignoring MPD Status Update May 26 17:18:13 rivo-streamer volumio[3124]: info: sendMpdCommand clear took 4 milliseconds May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.2.13:50002/m/NDLNA/22153.dsf" May 26 17:18:13 rivo-streamer volumio[3124]: info: May 26 17:18:13 rivo-streamer volumio[3124]: ---------------------------- MPD announces system playlist update May 26 17:18:13 rivo-streamer volumio[3124]: info: Ignoring MPD Status Update May 26 17:18:13 rivo-streamer volumio[3124]: info: May 26 17:18:13 rivo-streamer volumio[3124]: ---------------------------- MPD announces system playlist update May 26 17:18:13 rivo-streamer volumio[3124]: info: Ignoring MPD Status Update May 26 17:18:13 rivo-streamer volumio[3124]: error: updateQueue error: null May 26 17:18:13 rivo-streamer mpd[3647]: exception: No such playlist May 26 17:18:13 rivo-streamer volumio[3124]: info: ------------------------------ 14ms May 26 17:18:13 rivo-streamer volumio[3124]: error: Upnp client error: Error: This socket has been ended by the other party May 26 17:18:13 rivo-streamer volumio[3124]: error: updateQueue error: null May 26 17:18:13 rivo-streamer volumio[3124]: error: updateQueue error: null May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.2.13:50002/m/NDLNA/22153.dsf" May 26 17:18:13 rivo-streamer volumio[3124]: info: ------------------------------ 14ms May 26 17:18:13 rivo-streamer volumio[3124]: info: ------------------------------ 13ms May 26 17:18:13 rivo-streamer volumio[3124]: info: May 26 17:18:13 rivo-streamer volumio[3124]: ---------------------------- MPD announces system playlist update May 26 17:18:13 rivo-streamer volumio[3124]: info: Ignoring MPD Status Update May 26 17:18:13 rivo-streamer volumio[3124]: info: sendMpdCommand add "http://192.168.2.13:50002/m/NDLNA/22153.dsf" took 5 milliseconds May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::setConsumeUpdateService mpd May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand play May 26 17:18:13 rivo-streamer volumio[3124]: info: May 26 17:18:13 rivo-streamer volumio[3124]: ---------------------------- MPD announces system playlist update May 26 17:18:13 rivo-streamer volumio[3124]: info: Ignoring MPD Status Update May 26 17:18:13 rivo-streamer volumio[3124]: info: May 26 17:18:13 rivo-streamer volumio[3124]: ---------------------------- MPD announces system playlist update May 26 17:18:13 rivo-streamer volumio[3124]: info: Ignoring MPD Status Update May 26 17:18:13 rivo-streamer volumio[3124]: info: ------------------------------ 11ms May 26 17:18:13 rivo-streamer volumio[3124]: info: sendMpdCommand play took 9 milliseconds May 26 17:18:13 rivo-streamer volumio[3124]: info: ------------------------------ 8ms May 26 17:18:13 rivo-streamer volumio[3124]: info: ------------------------------ 7ms May 26 17:18:13 rivo-streamer kernel: aml_tdm_open May 26 17:18:13 rivo-streamer kernel: Not init audio effects May 26 17:18:13 rivo-streamer kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:tdm@1 May 26 17:18:13 rivo-streamer kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk May 26 17:18:13 rivo-streamer kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk May 26 17:18:13 rivo-streamer kernel: set mclk:12288000, mpll:24576000, get mclk:12287994, mpll:24575987 May 26 17:18:13 rivo-streamer kernel: asoc aml_dai_set_tdm_fmt, 0x4001, ffffffc03d00fc18, id(1), clksel(1) May 26 17:18:13 rivo-streamer kernel: aml_dai_set_tdm_fmt(), fmt not change May 26 17:18:13 rivo-streamer kernel: dump_pcm_setting(ffffffc03d00fc18) May 26 17:18:13 rivo-streamer kernel: pcm_mode(1) May 26 17:18:13 rivo-streamer kernel: sysclk(12288000) May 26 17:18:13 rivo-streamer kernel: sysclk_bclk_ratio(4) May 26 17:18:13 rivo-streamer kernel: bclk(3072000) May 26 17:18:13 rivo-streamer kernel: bclk_lrclk_ratio(64) May 26 17:18:13 rivo-streamer kernel: lrclk(48000) May 26 17:18:13 rivo-streamer kernel: tx_mask(0x3) May 26 17:18:13 rivo-streamer kernel: rx_mask(0x3) May 26 17:18:13 rivo-streamer kernel: slots(2) May 26 17:18:13 rivo-streamer kernel: slot_width(32) May 26 17:18:13 rivo-streamer kernel: lane_mask_in(0x2) May 26 17:18:13 rivo-streamer kernel: lane_mask_out(0x1) May 26 17:18:13 rivo-streamer kernel: lane_oe_mask_in(0x0) May 26 17:18:13 rivo-streamer kernel: lane_oe_mask_out(0x0) May 26 17:18:13 rivo-streamer kernel: lane_lb_mask_in(0x0) May 26 17:18:13 rivo-streamer kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk May 26 17:18:13 rivo-streamer kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk May 26 17:18:13 rivo-streamer kernel: set mclk:12288000, mpll:24576000, get mclk:12287994, mpll:24575987 May 26 17:18:13 rivo-streamer kernel: aml_dai_set_clkdiv, div 4, clksel(1) May 26 17:18:13 rivo-streamer kernel: aml_dai_set_bclk_ratio, select I2S mode May 26 17:18:13 rivo-streamer kernel: aml_dai_tdm_hw_params(), enable mclk for TDM-B May 26 17:18:13 rivo-streamer kernel: aml_tdm_prepare(), reset fddr May 26 17:18:13 rivo-streamer kernel: spdif_a fifo ctrl, frddr:0 type:1, 16 bits, chmask 0x3, swap 0x10 May 26 17:18:13 rivo-streamer kernel: spdif_info: rate: 48000, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x200, ch1_r:0x200 May 26 17:18:13 rivo-streamer kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 May 26 17:18:13 rivo-streamer kernel: tdm playback mute: 0, lane_cnt = 8 May 26 17:18:13 rivo-streamer kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 May 26 17:18:13 rivo-streamer kernel: aml_dai_tdm_hw_free(), disable mclk for TDM-B May 26 17:18:13 rivo-streamer kernel: set mclk:49152000, mpll:98304000, get mclk:49151901, mpll:98303801 May 26 17:18:13 rivo-streamer kernel: asoc aml_dai_set_tdm_fmt, 0x4001, ffffffc03d00fc18, id(1), clksel(1) May 26 17:18:13 rivo-streamer kernel: aml_dai_set_tdm_fmt(), fmt not change May 26 17:18:13 rivo-streamer kernel: dump_pcm_setting(ffffffc03d00fc18) May 26 17:18:13 rivo-streamer kernel: pcm_mode(1) May 26 17:18:13 rivo-streamer kernel: sysclk(49152000) May 26 17:18:13 rivo-streamer kernel: sysclk_bclk_ratio(4) May 26 17:18:13 rivo-streamer kernel: bclk(12288000) May 26 17:18:13 rivo-streamer kernel: bclk_lrclk_ratio(64) May 26 17:18:13 rivo-streamer kernel: lrclk(192000) May 26 17:18:13 rivo-streamer kernel: tx_mask(0x3) May 26 17:18:13 rivo-streamer kernel: rx_mask(0x3) May 26 17:18:13 rivo-streamer kernel: slots(2) May 26 17:18:13 rivo-streamer kernel: slot_width(32) May 26 17:18:13 rivo-streamer kernel: lane_mask_in(0x2) May 26 17:18:13 rivo-streamer kernel: lane_mask_out(0x1) May 26 17:18:13 rivo-streamer kernel: lane_oe_mask_in(0x0) May 26 17:18:13 rivo-streamer kernel: lane_oe_mask_out(0x0) May 26 17:18:13 rivo-streamer kernel: lane_lb_mask_in(0x0) May 26 17:18:13 rivo-streamer kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk May 26 17:18:13 rivo-streamer kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk May 26 17:18:13 rivo-streamer kernel: set mclk:49152000, mpll:98304000, get mclk:49151901, mpll:98303801 May 26 17:18:13 rivo-streamer kernel: aml_dai_set_clkdiv, div 4, clksel(1) May 26 17:18:13 rivo-streamer kernel: aml_dai_set_bclk_ratio, select I2S mode May 26 17:18:13 rivo-streamer kernel: aml_dai_tdm_hw_params(), enable mclk for TDM-B May 26 17:18:13 rivo-streamer kernel: aml_tdm_prepare(), reset fddr May 26 17:18:13 rivo-streamer kernel: spdif_a fifo ctrl, frddr:0 type:1, 16 bits, chmask 0x3, swap 0x10 May 26 17:18:13 rivo-streamer kernel: spdif_info: rate: 192000, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0xe00, ch1_r:0xe00 May 26 17:18:13 rivo-streamer kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 May 26 17:18:13 rivo-streamer kernel: tdm playback mute: 0, lane_cnt = 8 May 26 17:18:13 rivo-streamer kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 May 26 17:18:13 rivo-streamer kernel: aml_dai_tdm_hw_free(), disable mclk for TDM-B May 26 17:18:13 rivo-streamer kernel: tdm playback mute: 1, lane_cnt = 8 May 26 17:18:13 rivo-streamer kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:tdm@1 May 26 17:18:13 rivo-streamer volumio[3124]: info: May 26 17:18:13 rivo-streamer volumio[3124]: ---------------------------- MPD announces state update: player May 26 17:18:13 rivo-streamer volumio[3124]: info: ControllerMpd::getState May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand status May 26 17:18:13 rivo-streamer volumio[3124]: info: May 26 17:18:13 rivo-streamer volumio[3124]: ---------------------------- MPD announces state update: player May 26 17:18:13 rivo-streamer volumio[3124]: info: ControllerMpd::getState May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand status May 26 17:18:13 rivo-streamer mpd[3647]: exception: Failed to open "default detected output" (sndio); Requested audio params cannot be satisfied May 26 17:18:13 rivo-streamer mpd[3647]: player: problems opening audio device while playing "http://192.168.2.13:50002/m/NDLNA/22153.dsf" May 26 17:18:13 rivo-streamer volumio[3124]: info: May 26 17:18:13 rivo-streamer volumio[3124]: ---------------------------- MPD announces state update: player May 26 17:18:13 rivo-streamer volumio[3124]: info: ControllerMpd::getState May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand status May 26 17:18:13 rivo-streamer volumio[3124]: info: May 26 17:18:13 rivo-streamer volumio[3124]: ---------------------------- MPD announces state update: player May 26 17:18:13 rivo-streamer volumio[3124]: info: ControllerMpd::getState May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand status May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand clearerror May 26 17:18:13 rivo-streamer volumio[3124]: info: sendMpdCommand status took 17 milliseconds May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand clearerror May 26 17:18:13 rivo-streamer volumio[3124]: info: sendMpdCommand status took 14 milliseconds May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::parseState May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::parseState May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 26 17:18:13 rivo-streamer volumio[3124]: info: May 26 17:18:13 rivo-streamer volumio[3124]: ---------------------------- MPD announces state update: player May 26 17:18:13 rivo-streamer volumio[3124]: info: ControllerMpd::getState May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand status May 26 17:18:13 rivo-streamer volumio[3124]: info: May 26 17:18:13 rivo-streamer volumio[3124]: ---------------------------- MPD announces state update: player May 26 17:18:13 rivo-streamer volumio[3124]: info: ControllerMpd::getState May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand status May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand clearerror May 26 17:18:13 rivo-streamer volumio[3124]: info: sendMpdCommand status took 47 milliseconds May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand clearerror May 26 17:18:13 rivo-streamer volumio[3124]: info: sendMpdCommand status took 48 milliseconds May 26 17:18:13 rivo-streamer volumio[3124]: info: sendMpdCommand clearerror took 42 milliseconds May 26 17:18:13 rivo-streamer volumio[3124]: info: sendMpdCommand clearerror took 41 milliseconds May 26 17:18:13 rivo-streamer volumio[3124]: info: sendMpdCommand playlistinfo took 35 milliseconds May 26 17:18:13 rivo-streamer volumio[3124]: info: sendMpdCommand playlistinfo took 31 milliseconds May 26 17:18:13 rivo-streamer volumio[3124]: info: sendMpdCommand status took 23 milliseconds May 26 17:18:13 rivo-streamer volumio[3124]: info: sendMpdCommand status took 19 milliseconds May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::parseState May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::parseState May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::parseTrackInfo May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::parseTrackInfo May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::parseState May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::parseState May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 26 17:18:13 rivo-streamer volumio[3124]: info: ControllerMpd::pushState May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::servicePushState May 26 17:18:13 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrack 0 May 26 17:18:13 rivo-streamer volumio[3124]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":202,"samplerate":"11.28 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22153.dsf","artist":null,"album":null,"uri":"http://192.168.2.13:50002/m/NDLNA/22153.dsf","trackType":"dsf"} May 26 17:18:13 rivo-streamer volumio[3124]: verbose: CURRENT POSITION 0 May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::syncState stateService pause May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::syncState currentStatus stop May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::pushState May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushState May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioGetState May 26 17:18:13 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output update for this device May 26 17:18:13 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output May 26 17:18:13 rivo-streamer volumio[3124]: info: ControllerMpd::pushState May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::servicePushState May 26 17:18:13 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrack 0 May 26 17:18:13 rivo-streamer volumio[3124]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":202,"samplerate":"11.28 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22153.dsf","artist":null,"album":null,"uri":"http://192.168.2.13:50002/m/NDLNA/22153.dsf","trackType":"dsf"} May 26 17:18:13 rivo-streamer volumio[3124]: verbose: CURRENT POSITION 0 May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::syncState stateService pause May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::syncState currentStatus stop May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::pushState May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushState May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioGetState May 26 17:18:13 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output update for this device May 26 17:18:13 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output May 26 17:18:13 rivo-streamer volumio[3124]: info: ------------------------------ 127ms May 26 17:18:13 rivo-streamer volumio[3124]: info: ------------------------------ 123ms May 26 17:18:13 rivo-streamer volumio[3124]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined May 26 17:18:13 rivo-streamer volumio[3124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 26 17:18:13 rivo-streamer volumio[3124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 26 17:18:13 rivo-streamer volumio[3124]: info: sendMpdCommand clearerror took 94 milliseconds May 26 17:18:13 rivo-streamer volumio[3124]: info: sendMpdCommand clearerror took 92 milliseconds May 26 17:18:13 rivo-streamer volumio[3124]: info: sendMpdCommand playlistinfo took 77 milliseconds May 26 17:18:13 rivo-streamer volumio[3124]: info: sendMpdCommand playlistinfo took 77 milliseconds May 26 17:18:13 rivo-streamer volumio[3124]: info: sendMpdCommand playlistinfo took 70 milliseconds May 26 17:18:13 rivo-streamer volumio[3124]: info: sendMpdCommand playlistinfo took 70 milliseconds May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::parseTrackInfo May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::parseTrackInfo May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::parseTrackInfo May 26 17:18:13 rivo-streamer volumio[3124]: verbose: ControllerMpd::parseTrackInfo May 26 17:18:13 rivo-streamer volumio[3124]: info: ControllerMpd::pushState May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::servicePushState May 26 17:18:13 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrack 0 May 26 17:18:13 rivo-streamer volumio[3124]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":202,"samplerate":"11.28 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22153.dsf","artist":null,"album":null,"uri":"http://192.168.2.13:50002/m/NDLNA/22153.dsf","trackType":"dsf"} May 26 17:18:13 rivo-streamer volumio[3124]: verbose: CURRENT POSITION 0 May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::syncState stateService pause May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::syncState currentStatus stop May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::pushState May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushState May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioGetState May 26 17:18:13 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output update for this device May 26 17:18:13 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output May 26 17:18:13 rivo-streamer volumio[3124]: info: ControllerMpd::pushState May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::servicePushState May 26 17:18:13 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrack 0 May 26 17:18:13 rivo-streamer volumio[3124]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":202,"samplerate":"11.28 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22153.dsf","artist":null,"album":null,"uri":"http://192.168.2.13:50002/m/NDLNA/22153.dsf","trackType":"dsf"} May 26 17:18:13 rivo-streamer volumio[3124]: verbose: CURRENT POSITION 0 May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::syncState stateService pause May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::syncState currentStatus stop May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::pushState May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushState May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioGetState May 26 17:18:13 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output update for this device May 26 17:18:13 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output May 26 17:18:13 rivo-streamer volumio[3124]: info: ControllerMpd::pushState May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::servicePushState May 26 17:18:13 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrack 0 May 26 17:18:13 rivo-streamer volumio[3124]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":202,"samplerate":"11.28 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22153.dsf","artist":null,"album":null,"uri":"http://192.168.2.13:50002/m/NDLNA/22153.dsf","trackType":"dsf"} May 26 17:18:13 rivo-streamer volumio[3124]: verbose: CURRENT POSITION 0 May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::syncState stateService pause May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::syncState currentStatus stop May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::pushState May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushState May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioGetState May 26 17:18:13 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output update for this device May 26 17:18:13 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output May 26 17:18:13 rivo-streamer volumio[3124]: info: ControllerMpd::pushState May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::servicePushState May 26 17:18:13 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrack 0 May 26 17:18:13 rivo-streamer volumio[3124]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":202,"samplerate":"11.28 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22153.dsf","artist":null,"album":null,"uri":"http://192.168.2.13:50002/m/NDLNA/22153.dsf","trackType":"dsf"} May 26 17:18:13 rivo-streamer volumio[3124]: verbose: CURRENT POSITION 0 May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::syncState stateService pause May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::syncState currentStatus stop May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreStateMachine::pushState May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushState May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioGetState May 26 17:18:13 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output update for this device May 26 17:18:13 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output May 26 17:18:13 rivo-streamer volumio[3124]: info: ------------------------------ 199ms May 26 17:18:13 rivo-streamer volumio[3124]: info: ------------------------------ 198ms May 26 17:18:13 rivo-streamer volumio[3124]: info: ------------------------------ 173ms May 26 17:18:13 rivo-streamer volumio[3124]: info: ------------------------------ 167ms May 26 17:18:13 rivo-streamer volumio[3124]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined May 26 17:18:13 rivo-streamer volumio[3124]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined May 26 17:18:13 rivo-streamer volumio[3124]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined May 26 17:18:13 rivo-streamer volumio[3124]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined May 26 17:18:13 rivo-streamer volumio[3124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 26 17:18:13 rivo-streamer volumio[3124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 26 17:18:13 rivo-streamer volumio[3124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 26 17:18:13 rivo-streamer volumio[3124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 26 17:18:13 rivo-streamer volumio[3124]: info: Discovery: Getting this device information May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioGetState May 26 17:18:13 rivo-streamer volumio[3124]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 26 17:18:22 rivo-streamer volumio[3124]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 26 17:18:22 rivo-streamer volumio[3124]: info: Preload queue cleared May 26 17:18:22 rivo-streamer volumio[3124]: info: Preloading song: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@18578 May 26 17:18:22 rivo-streamer volumio[3124]: info: Preloading song: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@18581 May 26 17:18:22 rivo-streamer volumio[3124]: info: Preloading song: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@18580 May 26 17:18:22 rivo-streamer volumio[3124]: info: Preloading song: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@18583 May 26 17:18:22 rivo-streamer volumio[3124]: info: Preloading song: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@18582 May 26 17:18:22 rivo-streamer volumio[3124]: info: Preloading song: upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@18584 May 26 17:18:22 rivo-streamer volumio[3124]: info: Exploding uri upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@18578 in service upnp_browser May 26 17:18:22 rivo-streamer volumio[3124]: info: Exploding uri upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@18581 in service upnp_browser May 26 17:18:22 rivo-streamer volumio[3124]: info: Exploding uri upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@18580 in service upnp_browser May 26 17:18:22 rivo-streamer volumio[3124]: info: Exploding uri upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@18583 in service upnp_browser May 26 17:18:22 rivo-streamer volumio[3124]: info: Exploding uri upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@18582 in service upnp_browser May 26 17:18:22 rivo-streamer volumio[3124]: info: Exploding uri upnp/http://192.168.2.13:50001/ContentDirectory/control@22$@18584 in service upnp_browser May 26 17:18:23 rivo-streamer volumio[3124]: info: Preload queue cleared May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioReplaceandPlayItems May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::ClearQueue May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::stop May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 17:18:23 rivo-streamer volumio[3124]: info: CorePlayQueue::clearPlayQueue May 26 17:18:23 rivo-streamer volumio[3124]: info: CorePlayQueue::saveQueue May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushQueue May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::addQueueItems May 26 17:18:23 rivo-streamer volumio[3124]: info: CorePlayQueue::addQueueItems May 26 17:18:23 rivo-streamer volumio[3124]: info: Preload queue cleared May 26 17:18:23 rivo-streamer volumio[3124]: info: Adding Item to queue: upnp/folder/http://192.168.2.13:50001/ContentDirectory/control@22$2199 May 26 17:18:23 rivo-streamer volumio[3124]: info: Exploding uri upnp/folder/http://192.168.2.13:50001/ContentDirectory/control@22$2199 in service upnp_browser May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushQueue May 26 17:18:23 rivo-streamer volumio[3124]: info: CorePlayQueue::saveQueue May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::updateTrackBlock May 26 17:18:23 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrackBlock May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPlay May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::play index 0 May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::stop May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::play index undefined May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 17:18:23 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrack 0 May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::startPlaybackTimer May 26 17:18:23 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrack 0 May 26 17:18:23 rivo-streamer volumio[3124]: info: [1748251103389] ControllerUPNPBrowser::clearAddPlayTrack May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand stop May 26 17:18:23 rivo-streamer mpd[3647]: player: played "http://192.168.2.13:50002/m/NDLNA/22153.dsf" May 26 17:18:23 rivo-streamer volumio[3124]: info: May 26 17:18:23 rivo-streamer volumio[3124]: ---------------------------- MPD announces state update: player May 26 17:18:23 rivo-streamer volumio[3124]: info: sendMpdCommand stop took 9 milliseconds May 26 17:18:23 rivo-streamer volumio[3124]: info: ControllerMpd::getState May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand status May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand clear May 26 17:18:23 rivo-streamer volumio[3124]: info: May 26 17:18:23 rivo-streamer volumio[3124]: ---------------------------- MPD announces system playlist update May 26 17:18:23 rivo-streamer volumio[3124]: info: Ignoring MPD Status Update May 26 17:18:23 rivo-streamer volumio[3124]: info: sendMpdCommand status took 4 milliseconds May 26 17:18:23 rivo-streamer volumio[3124]: info: sendMpdCommand clear took 4 milliseconds May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::parseState May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.2.13:50002/m/NDLNA/18578.dsf" May 26 17:18:23 rivo-streamer volumio[3124]: info: May 26 17:18:23 rivo-streamer volumio[3124]: ---------------------------- MPD announces state update: player May 26 17:18:23 rivo-streamer volumio[3124]: info: ControllerMpd::getState May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand status May 26 17:18:23 rivo-streamer volumio[3124]: info: May 26 17:18:23 rivo-streamer volumio[3124]: ---------------------------- MPD announces state update: player May 26 17:18:23 rivo-streamer volumio[3124]: info: ControllerMpd::getState May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand status May 26 17:18:23 rivo-streamer volumio[3124]: error: updateQueue error: null May 26 17:18:23 rivo-streamer volumio[3124]: info: ------------------------------ 16ms May 26 17:18:23 rivo-streamer volumio[3124]: info: sendMpdCommand playlistinfo took 12 milliseconds May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::parseTrackInfo May 26 17:18:23 rivo-streamer volumio[3124]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined May 26 17:18:23 rivo-streamer volumio[3124]: info: ------------------------------ 23ms May 26 17:18:23 rivo-streamer mpd[3647]: exception: No such playlist May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.2.13:50002/m/NDLNA/18578.dsf" May 26 17:18:23 rivo-streamer volumio[3124]: info: May 26 17:18:23 rivo-streamer volumio[3124]: ---------------------------- MPD announces system playlist update May 26 17:18:23 rivo-streamer volumio[3124]: info: Ignoring MPD Status Update May 26 17:18:23 rivo-streamer volumio[3124]: info: sendMpdCommand status took 47 milliseconds May 26 17:18:23 rivo-streamer volumio[3124]: info: sendMpdCommand status took 45 milliseconds May 26 17:18:23 rivo-streamer volumio[3124]: info: sendMpdCommand add "http://192.168.2.13:50002/m/NDLNA/18578.dsf" took 3 milliseconds May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::parseState May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::parseState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::setConsumeUpdateService mpd May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand play May 26 17:18:23 rivo-streamer volumio[3124]: info: ControllerMpd::pushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::servicePushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::pushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioGetState May 26 17:18:23 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output update for this device May 26 17:18:23 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output May 26 17:18:23 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrack 0 May 26 17:18:23 rivo-streamer volumio[3124]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 26 17:18:23 rivo-streamer volumio[3124]: verbose: CURRENT POSITION 0 May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::syncState stateService stop May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::syncState currentStatus stop May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::pushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioGetState May 26 17:18:23 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output update for this device May 26 17:18:23 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output May 26 17:18:23 rivo-streamer volumio[3124]: info: No code May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::pushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioGetState May 26 17:18:23 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output update for this device May 26 17:18:23 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output May 26 17:18:23 rivo-streamer volumio[3124]: info: ControllerMpd::pushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::servicePushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::pushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioGetState May 26 17:18:23 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output update for this device May 26 17:18:23 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output May 26 17:18:23 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrack 0 May 26 17:18:23 rivo-streamer volumio[3124]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 26 17:18:23 rivo-streamer volumio[3124]: verbose: CURRENT POSITION 0 May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::syncState stateService stop May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::syncState currentStatus stop May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::pushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioGetState May 26 17:18:23 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output update for this device May 26 17:18:23 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output May 26 17:18:23 rivo-streamer volumio[3124]: info: No code May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::pushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioGetState May 26 17:18:23 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output update for this device May 26 17:18:23 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output May 26 17:18:23 rivo-streamer kernel: aml_tdm_open May 26 17:18:23 rivo-streamer kernel: Not init audio effects May 26 17:18:23 rivo-streamer kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:tdm@1 May 26 17:18:23 rivo-streamer kernel: set mclk:12288000, mpll:24576000, get mclk:12287994, mpll:24575987 May 26 17:18:23 rivo-streamer kernel: asoc aml_dai_set_tdm_fmt, 0x4001, ffffffc03d00fc18, id(1), clksel(1) May 26 17:18:23 rivo-streamer kernel: aml_dai_set_tdm_fmt(), fmt not change May 26 17:18:23 rivo-streamer kernel: dump_pcm_setting(ffffffc03d00fc18) May 26 17:18:23 rivo-streamer kernel: pcm_mode(1) May 26 17:18:23 rivo-streamer kernel: sysclk(12288000) May 26 17:18:23 rivo-streamer kernel: sysclk_bclk_ratio(4) May 26 17:18:23 rivo-streamer kernel: bclk(3072000) May 26 17:18:23 rivo-streamer kernel: bclk_lrclk_ratio(64) May 26 17:18:23 rivo-streamer kernel: lrclk(48000) May 26 17:18:23 rivo-streamer kernel: tx_mask(0x3) May 26 17:18:23 rivo-streamer kernel: rx_mask(0x3) May 26 17:18:23 rivo-streamer kernel: slots(2) May 26 17:18:23 rivo-streamer kernel: slot_width(32) May 26 17:18:23 rivo-streamer kernel: lane_mask_in(0x2) May 26 17:18:23 rivo-streamer kernel: lane_mask_out(0x1) May 26 17:18:23 rivo-streamer kernel: lane_oe_mask_in(0x0) May 26 17:18:23 rivo-streamer kernel: lane_oe_mask_out(0x0) May 26 17:18:23 rivo-streamer kernel: lane_lb_mask_in(0x0) May 26 17:18:23 rivo-streamer kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk May 26 17:18:23 rivo-streamer kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk May 26 17:18:23 rivo-streamer kernel: set mclk:12288000, mpll:24576000, get mclk:12287994, mpll:24575987 May 26 17:18:23 rivo-streamer kernel: aml_dai_set_clkdiv, div 4, clksel(1) May 26 17:18:23 rivo-streamer kernel: aml_dai_set_bclk_ratio, select I2S mode May 26 17:18:23 rivo-streamer kernel: aml_dai_tdm_hw_params(), enable mclk for TDM-B May 26 17:18:23 rivo-streamer kernel: aml_tdm_prepare(), reset fddr May 26 17:18:23 rivo-streamer kernel: spdif_a fifo ctrl, frddr:0 type:1, 16 bits, chmask 0x3, swap 0x10 May 26 17:18:23 rivo-streamer kernel: spdif_info: rate: 48000, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x200, ch1_r:0x200 May 26 17:18:23 rivo-streamer kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 May 26 17:18:23 rivo-streamer kernel: tdm playback mute: 0, lane_cnt = 8 May 26 17:18:23 rivo-streamer kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 May 26 17:18:23 rivo-streamer kernel: aml_dai_tdm_hw_free(), disable mclk for TDM-B May 26 17:18:23 rivo-streamer kernel: set mclk:49152000, mpll:98304000, get mclk:49151901, mpll:98303801 May 26 17:18:23 rivo-streamer kernel: asoc aml_dai_set_tdm_fmt, 0x4001, ffffffc03d00fc18, id(1), clksel(1) May 26 17:18:23 rivo-streamer kernel: aml_dai_set_tdm_fmt(), fmt not change May 26 17:18:23 rivo-streamer kernel: dump_pcm_setting(ffffffc03d00fc18) May 26 17:18:23 rivo-streamer kernel: pcm_mode(1) May 26 17:18:23 rivo-streamer kernel: sysclk(49152000) May 26 17:18:23 rivo-streamer kernel: sysclk_bclk_ratio(4) May 26 17:18:23 rivo-streamer kernel: bclk(12288000) May 26 17:18:23 rivo-streamer kernel: bclk_lrclk_ratio(64) May 26 17:18:23 rivo-streamer kernel: lrclk(192000) May 26 17:18:23 rivo-streamer kernel: tx_mask(0x3) May 26 17:18:23 rivo-streamer kernel: rx_mask(0x3) May 26 17:18:23 rivo-streamer kernel: slots(2) May 26 17:18:23 rivo-streamer kernel: slot_width(32) May 26 17:18:23 rivo-streamer kernel: lane_mask_in(0x2) May 26 17:18:23 rivo-streamer kernel: lane_mask_out(0x1) May 26 17:18:23 rivo-streamer kernel: lane_oe_mask_in(0x0) May 26 17:18:23 rivo-streamer kernel: lane_oe_mask_out(0x0) May 26 17:18:23 rivo-streamer kernel: lane_lb_mask_in(0x0) May 26 17:18:23 rivo-streamer kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk May 26 17:18:23 rivo-streamer kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk May 26 17:18:23 rivo-streamer kernel: set mclk:49152000, mpll:98304000, get mclk:49151901, mpll:98303801 May 26 17:18:23 rivo-streamer kernel: aml_dai_set_clkdiv, div 4, clksel(1) May 26 17:18:23 rivo-streamer kernel: aml_dai_set_bclk_ratio, select I2S mode May 26 17:18:23 rivo-streamer kernel: aml_dai_tdm_hw_params(), enable mclk for TDM-B May 26 17:18:23 rivo-streamer kernel: aml_tdm_prepare(), reset fddr May 26 17:18:23 rivo-streamer kernel: spdif_a fifo ctrl, frddr:0 type:1, 16 bits, chmask 0x3, swap 0x10 May 26 17:18:23 rivo-streamer kernel: spdif_info: rate: 192000, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0xe00, ch1_r:0xe00 May 26 17:18:23 rivo-streamer kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 May 26 17:18:23 rivo-streamer kernel: tdm playback mute: 0, lane_cnt = 8 May 26 17:18:23 rivo-streamer kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 May 26 17:18:23 rivo-streamer kernel: aml_dai_tdm_hw_free(), disable mclk for TDM-B May 26 17:18:23 rivo-streamer kernel: tdm playback mute: 1, lane_cnt = 8 May 26 17:18:23 rivo-streamer kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:tdm@1 May 26 17:18:23 rivo-streamer mpd[3647]: exception: Failed to open "default detected output" (sndio); Requested audio params cannot be satisfied May 26 17:18:23 rivo-streamer mpd[3647]: player: problems opening audio device while playing "http://192.168.2.13:50002/m/NDLNA/18578.dsf" May 26 17:18:23 rivo-streamer volumio[3124]: info: ------------------------------ 133ms May 26 17:18:23 rivo-streamer volumio[3124]: info: ------------------------------ 132ms May 26 17:18:23 rivo-streamer volumio[3124]: info: May 26 17:18:23 rivo-streamer volumio[3124]: ---------------------------- MPD announces system playlist update May 26 17:18:23 rivo-streamer volumio[3124]: info: Ignoring MPD Status Update May 26 17:18:23 rivo-streamer volumio[3124]: info: May 26 17:18:23 rivo-streamer volumio[3124]: ---------------------------- MPD announces system playlist update May 26 17:18:23 rivo-streamer volumio[3124]: info: Ignoring MPD Status Update May 26 17:18:23 rivo-streamer volumio[3124]: info: May 26 17:18:23 rivo-streamer volumio[3124]: ---------------------------- MPD announces state update: player May 26 17:18:23 rivo-streamer volumio[3124]: info: May 26 17:18:23 rivo-streamer volumio[3124]: ---------------------------- MPD announces state update: player May 26 17:18:23 rivo-streamer volumio[3124]: info: ------------------------------ 98ms May 26 17:18:23 rivo-streamer volumio[3124]: info: sendMpdCommand play took 94 milliseconds May 26 17:18:23 rivo-streamer volumio[3124]: info: ControllerMpd::getState May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand status May 26 17:18:23 rivo-streamer volumio[3124]: info: ------------------------------ 12ms May 26 17:18:23 rivo-streamer volumio[3124]: info: ControllerMpd::getState May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand status May 26 17:18:23 rivo-streamer volumio[3124]: info: ------------------------------ 14ms May 26 17:18:23 rivo-streamer volumio[3124]: info: May 26 17:18:23 rivo-streamer volumio[3124]: ---------------------------- MPD announces system playlist update May 26 17:18:23 rivo-streamer volumio[3124]: info: Ignoring MPD Status Update May 26 17:18:23 rivo-streamer volumio[3124]: info: May 26 17:18:23 rivo-streamer volumio[3124]: ---------------------------- MPD announces state update: player May 26 17:18:23 rivo-streamer volumio[3124]: info: ControllerMpd::getState May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand status May 26 17:18:23 rivo-streamer volumio[3124]: info: May 26 17:18:23 rivo-streamer volumio[3124]: ---------------------------- MPD announces system playlist update May 26 17:18:23 rivo-streamer volumio[3124]: info: Ignoring MPD Status Update May 26 17:18:23 rivo-streamer volumio[3124]: info: May 26 17:18:23 rivo-streamer volumio[3124]: ---------------------------- MPD announces state update: player May 26 17:18:23 rivo-streamer volumio[3124]: info: ControllerMpd::getState May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand status May 26 17:18:23 rivo-streamer volumio[3124]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined May 26 17:18:23 rivo-streamer volumio[3124]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined May 26 17:18:23 rivo-streamer volumio[3124]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined May 26 17:18:23 rivo-streamer volumio[3124]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined May 26 17:18:23 rivo-streamer volumio[3124]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined May 26 17:18:23 rivo-streamer volumio[3124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 26 17:18:23 rivo-streamer volumio[3124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 26 17:18:23 rivo-streamer volumio[3124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 26 17:18:23 rivo-streamer volumio[3124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 26 17:18:23 rivo-streamer volumio[3124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 26 17:18:23 rivo-streamer volumio[3124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand clearerror May 26 17:18:23 rivo-streamer volumio[3124]: info: sendMpdCommand status took 95 milliseconds May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand clearerror May 26 17:18:23 rivo-streamer volumio[3124]: info: sendMpdCommand status took 94 milliseconds May 26 17:18:23 rivo-streamer volumio[3124]: info: ------------------------------ 86ms May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand clearerror May 26 17:18:23 rivo-streamer volumio[3124]: info: sendMpdCommand status took 85 milliseconds May 26 17:18:23 rivo-streamer volumio[3124]: info: ------------------------------ 82ms May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand clearerror May 26 17:18:23 rivo-streamer volumio[3124]: info: sendMpdCommand status took 79 milliseconds May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::parseState May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::parseState May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::parseState May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::parseState May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 26 17:18:23 rivo-streamer volumio[3124]: info: sendMpdCommand clearerror took 28 milliseconds May 26 17:18:23 rivo-streamer volumio[3124]: info: sendMpdCommand clearerror took 27 milliseconds May 26 17:18:23 rivo-streamer volumio[3124]: info: sendMpdCommand clearerror took 25 milliseconds May 26 17:18:23 rivo-streamer volumio[3124]: info: sendMpdCommand clearerror took 24 milliseconds May 26 17:18:23 rivo-streamer volumio[3124]: info: sendMpdCommand playlistinfo took 15 milliseconds May 26 17:18:23 rivo-streamer volumio[3124]: info: sendMpdCommand playlistinfo took 15 milliseconds May 26 17:18:23 rivo-streamer volumio[3124]: info: sendMpdCommand playlistinfo took 13 milliseconds May 26 17:18:23 rivo-streamer volumio[3124]: info: sendMpdCommand playlistinfo took 10 milliseconds May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::parseTrackInfo May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::parseTrackInfo May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::parseTrackInfo May 26 17:18:23 rivo-streamer volumio[3124]: verbose: ControllerMpd::parseTrackInfo May 26 17:18:23 rivo-streamer volumio[3124]: info: ControllerMpd::pushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::servicePushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrack 0 May 26 17:18:23 rivo-streamer volumio[3124]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":833,"samplerate":"11.28 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"18578.dsf","artist":null,"album":null,"uri":"http://192.168.2.13:50002/m/NDLNA/18578.dsf","trackType":"dsf"} May 26 17:18:23 rivo-streamer volumio[3124]: verbose: CURRENT POSITION 0 May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::syncState stateService pause May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::syncState currentStatus stop May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::pushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioGetState May 26 17:18:23 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output update for this device May 26 17:18:23 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output May 26 17:18:23 rivo-streamer volumio[3124]: info: ControllerMpd::pushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::servicePushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrack 0 May 26 17:18:23 rivo-streamer volumio[3124]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":833,"samplerate":"11.28 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"18578.dsf","artist":null,"album":null,"uri":"http://192.168.2.13:50002/m/NDLNA/18578.dsf","trackType":"dsf"} May 26 17:18:23 rivo-streamer volumio[3124]: verbose: CURRENT POSITION 0 May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::syncState stateService pause May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::syncState currentStatus stop May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::pushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioGetState May 26 17:18:23 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output update for this device May 26 17:18:23 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output May 26 17:18:23 rivo-streamer volumio[3124]: info: ControllerMpd::pushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::servicePushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrack 0 May 26 17:18:23 rivo-streamer volumio[3124]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":833,"samplerate":"11.28 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"18578.dsf","artist":null,"album":null,"uri":"http://192.168.2.13:50002/m/NDLNA/18578.dsf","trackType":"dsf"} May 26 17:18:23 rivo-streamer volumio[3124]: verbose: CURRENT POSITION 0 May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::syncState stateService pause May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::syncState currentStatus stop May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::pushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioGetState May 26 17:18:23 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output update for this device May 26 17:18:23 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output May 26 17:18:23 rivo-streamer volumio[3124]: info: ControllerMpd::pushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::servicePushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CorePlayQueue::getTrack 0 May 26 17:18:23 rivo-streamer volumio[3124]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":833,"samplerate":"11.28 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"18578.dsf","artist":null,"album":null,"uri":"http://192.168.2.13:50002/m/NDLNA/18578.dsf","trackType":"dsf"} May 26 17:18:23 rivo-streamer volumio[3124]: verbose: CURRENT POSITION 0 May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::syncState stateService pause May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::syncState currentStatus stop May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreStateMachine::pushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioPushState May 26 17:18:23 rivo-streamer volumio[3124]: info: CoreCommandRouter::volumioGetState May 26 17:18:23 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output update for this device May 26 17:18:23 rivo-streamer volumio[3124]: info: MRS: Pushing multiroomSync output May 26 17:18:23 rivo-streamer volumio[3124]: info: ------------------------------ 206ms May 26 17:18:23 rivo-streamer volumio[3124]: info: ------------------------------ 206ms May 26 17:18:23 rivo-streamer volumio[3124]: info: ------------------------------ 190ms May 26 17:18:23 rivo-streamer volumio[3124]: info: ------------------------------ 183ms May 26 17:18:23 rivo-streamer volumio[3124]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined May 26 17:18:23 rivo-streamer volumio[3124]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined May 26 17:18:23 rivo-streamer volumio[3124]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined May 26 17:18:23 rivo-streamer volumio[3124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 26 17:18:23 rivo-streamer volumio[3124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 26 17:18:23 rivo-streamer volumio[3124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 26 17:18:23 rivo-streamer volumio[3124]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 26 17:18:32 rivo-streamer volumio[3124]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 26 17:18:32 rivo-streamer volumio[3124]: info: Preload queue cleared May 26 17:18:33 rivo-streamer volumio[3124]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 26 17:18:33 rivo-streamer volumio[3124]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 26 17:18:33 rivo-streamer volumio[3124]: TypeError: Cannot read property 'length' of undefined May 26 17:18:33 rivo-streamer volumio[3124]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 May 26 17:18:33 rivo-streamer volumio[3124]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 May 26 17:18:33 rivo-streamer volumio[3124]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) May 26 17:18:33 rivo-streamer volumio[3124]: at Parser.emit (events.js:400:28) May 26 17:18:33 rivo-streamer volumio[3124]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) May 26 17:18:33 rivo-streamer volumio[3124]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) May 26 17:18:33 rivo-streamer volumio[3124]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) May 26 17:18:33 rivo-streamer volumio[3124]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) May 26 17:18:33 rivo-streamer volumio[3124]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) May 26 17:18:33 rivo-streamer volumio[3124]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) May 26 17:18:33 rivo-streamer volumio[3124]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) May 26 17:18:33 rivo-streamer volumio[3124]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) May 26 17:18:33 rivo-streamer volumio[3124]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) May 26 17:18:33 rivo-streamer volumio[3124]: at IncomingMessage.emit (events.js:412:35) May 26 17:18:33 rivo-streamer volumio[3124]: at endReadableNT (internal/streams/readable.js:1333:12) May 26 17:18:33 rivo-streamer volumio[3124]: at processTicksAndRejections (internal/process/task_queues.js:82:21) May 26 17:18:33 rivo-streamer volumio[3124]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 26 17:18:34 rivo-streamer sudo[5638]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-26 17:17 May 26 17:18:34 rivo-streamer sudo[5638]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 30 Apr 2025 12:35:56 PM CEST" VOLUMIO_VERSION="3.807" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="ea561adf1e965df757744ffb8ecc9b8a"