-- Logs begin at Fri 2024-11-08 19:24:00 EET, end at Sun 2024-12-01 00:07:52 EET. -- Dec 01 00:06:13 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 01 00:06:13 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 01 00:06:13 rivoplus volumio[3429]: info: Discovery: Getting this device information Dec 01 00:06:13 rivoplus volumio[3429]: info: CoreCommandRouter::volumioGetState Dec 01 00:06:13 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 01 00:06:13 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 01 00:06:13 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 01 00:06:13 rivoplus volumio[3429]: info: Discovery: Getting this device information Dec 01 00:06:13 rivoplus volumio[3429]: info: CoreCommandRouter::volumioGetState Dec 01 00:06:13 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 01 00:06:13 rivoplus volumio[3429]: verbose: New Socket.io Connection to 192.168.1.53:3000 from 192.168.1.9 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Dec 01 00:06:13 rivoplus volumio[3429]: info: CoreCommandRouter::volumioGetState Dec 01 00:06:13 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 01 00:06:13 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 01 00:06:16 rivoplus sudo[5321]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 01 00:06:16 rivoplus sudo[5321]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 00:06:16 rivoplus sudo[5321]: pam_unix(sudo:session): session closed for user root Dec 01 00:06:16 rivoplus sudo[5324]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 01 00:06:16 rivoplus sudo[5324]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 00:06:16 rivoplus sudo[5324]: pam_unix(sudo:session): session closed for user root Dec 01 00:06:16 rivoplus volumio[3429]: verbose: New Socket.io Connection to 192.168.1.53 from 192.168.1.9 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 8 Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreCommandRouter::volumioGetVisibleSources Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreCommandRouter::volumioGetState Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 01 00:06:16 rivoplus volumio[3429]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Dec 01 00:06:16 rivoplus volumio[3429]: info: Received Get System Info Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 01 00:06:16 rivoplus volumio[3429]: info: Discovery: Getting this device information Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreCommandRouter::volumioGetState Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreCommandRouter::volumioGetState Dec 01 00:06:16 rivoplus volumio[3429]: info: Listing playlists Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 01 00:06:16 rivoplus sudo[5329]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 01 00:06:16 rivoplus sudo[5329]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 00:06:16 rivoplus sudo[5329]: pam_unix(sudo:session): session closed for user root Dec 01 00:06:16 rivoplus sudo[5333]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 01 00:06:16 rivoplus sudo[5333]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 00:06:16 rivoplus sudo[5333]: pam_unix(sudo:session): session closed for user root Dec 01 00:06:16 rivoplus volumio[3429]: verbose: New Socket.io Connection to 192.168.1.53 from 192.168.1.9 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 9 Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreCommandRouter::volumioGetVisibleSources Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreCommandRouter::volumioGetState Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreCommandRouter::volumioGetQueue Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreStateMachine::getQueue Dec 01 00:06:16 rivoplus volumio[3429]: info: CorePlayQueue::getQueue Dec 01 00:06:16 rivoplus volumio[3429]: info: Listing playlists Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 01 00:06:16 rivoplus volumio[3429]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Dec 01 00:06:16 rivoplus volumio[3429]: info: Received Get System Info Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 01 00:06:16 rivoplus volumio[3429]: info: Discovery: Getting this device information Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreCommandRouter::volumioGetState Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreCommandRouter::volumioGetState Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 01 00:06:16 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 01 00:06:17 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 01 00:06:17 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 01 00:06:17 rivoplus volumio[3429]: info: Discovery: Getting this device information Dec 01 00:06:17 rivoplus volumio[3429]: info: CoreCommandRouter::volumioGetState Dec 01 00:06:17 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 01 00:06:17 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 01 00:06:17 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 01 00:06:17 rivoplus volumio[3429]: info: Discovery: Getting this device information Dec 01 00:06:17 rivoplus volumio[3429]: info: CoreCommandRouter::volumioGetState Dec 01 00:06:17 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 01 00:06:18 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Dec 01 00:06:18 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 01 00:06:18 rivoplus volumio[3429]: info: Received Get System Info Dec 01 00:06:18 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 01 00:06:18 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 01 00:06:18 rivoplus volumio[3429]: info: Discovery: Getting this device information Dec 01 00:06:18 rivoplus volumio[3429]: info: CoreCommandRouter::volumioGetState Dec 01 00:06:18 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 01 00:06:19 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 01 00:06:19 rivoplus volumio[3429]: info: Received Get System Info Dec 01 00:06:19 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 01 00:06:19 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 01 00:06:19 rivoplus volumio[3429]: info: Discovery: Getting this device information Dec 01 00:06:19 rivoplus volumio[3429]: info: CoreCommandRouter::volumioGetState Dec 01 00:06:19 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 01 00:06:20 rivoplus volumio[3429]: info: Preload queue cleared Dec 01 00:06:20 rivoplus volumio[3429]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 01 00:06:20 rivoplus volumio[3429]: info: CoreStateMachine::ClearQueue Dec 01 00:06:20 rivoplus volumio[3429]: info: CoreStateMachine::stop Dec 01 00:06:20 rivoplus volumio[3429]: info: CoreStateMachine::serviceStop Dec 01 00:06:20 rivoplus volumio[3429]: info: CoreCommandRouter::serviceStop Dec 01 00:06:20 rivoplus volumio[3429]: info: CorePlayQueue::clearPlayQueue Dec 01 00:06:20 rivoplus volumio[3429]: info: CorePlayQueue::saveQueue Dec 01 00:06:20 rivoplus volumio[3429]: info: CoreCommandRouter::volumioPushQueue Dec 01 00:06:20 rivoplus volumio[3429]: info: CoreStateMachine::addQueueItems Dec 01 00:06:20 rivoplus volumio[3429]: info: CorePlayQueue::addQueueItems Dec 01 00:06:20 rivoplus volumio[3429]: info: Preload queue cleared Dec 01 00:06:20 rivoplus volumio[3429]: info: Adding Item to queue: http://yp.shoutcast.com/sbin/tunein-station.m3u?id=1677115 Dec 01 00:06:20 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Dec 01 00:06:20 rivoplus volumio[3429]: info: CoreCommandRouter::volumioPushQueue Dec 01 00:06:20 rivoplus volumio[3429]: info: CorePlayQueue::saveQueue Dec 01 00:06:20 rivoplus volumio[3429]: info: CoreStateMachine::updateTrackBlock Dec 01 00:06:20 rivoplus volumio[3429]: info: CorePlayQueue::getTrackBlock Dec 01 00:06:20 rivoplus volumio[3429]: info: CoreCommandRouter::volumioPlay Dec 01 00:06:20 rivoplus volumio[3429]: verbose: UNSET VOLATILE: Service: raat Dec 01 00:06:20 rivoplus volumio[3429]: info: RAAT Giving Up Control Dec 01 00:06:20 rivoplus volumio[3429]: info: CoreStateMachine::play index 0 Dec 01 00:06:20 rivoplus volumio[3429]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 01 00:06:20 rivoplus volumio[3429]: info: CoreStateMachine::stop Dec 01 00:06:20 rivoplus volumio[3429]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 01 00:06:20 rivoplus volumio[3429]: info: CoreStateMachine::updateTrackBlock Dec 01 00:06:20 rivoplus volumio[3429]: info: CorePlayQueue::getTrackBlock Dec 01 00:06:20 rivoplus volumio[3429]: info: CoreStateMachine::stPlaybackTimer Dec 01 00:06:20 rivoplus volumio[3429]: info: CoreStateMachine::pushState Dec 01 00:06:20 rivoplus volumio[3429]: info: CorePlayQueue::getTrack 0 Dec 01 00:06:20 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 00:06:20 rivoplus volumio[3429]: info: CoreCommandRouter::volumioPushState Dec 01 00:06:20 rivoplus volumio[3429]: info: MRS: Pushing multiroomSync output update for this device Dec 01 00:06:20 rivoplus volumio[3429]: info: MRS: Pushing multiroomSync output Dec 01 00:06:20 rivoplus volumio[3429]: info: CoreStateMachine::serviceStop Dec 01 00:06:20 rivoplus volumio[3429]: info: CorePlayQueue::getTrack 0 Dec 01 00:06:20 rivoplus volumio[3429]: info: CoreCommandRouter::serviceStop Dec 01 00:06:20 rivoplus volumio[3429]: info: [1733004380284] ControllerWebradio::stop Dec 01 00:06:20 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand stop Dec 01 00:06:20 rivoplus volumio[3429]: info: Updating RAAT Signal Path Dec 01 00:06:20 rivoplus volumio[3429]: info: RAAT Giving Up Control: OK Dec 01 00:06:20 rivoplus volumio[3429]: info: sendMpdCommand stop took 34 milliseconds Dec 01 00:06:20 rivoplus volumio[3429]: info: CoreStateMachine::play index undefined Dec 01 00:06:20 rivoplus volumio[3429]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 01 00:06:20 rivoplus volumio[3429]: info: CorePlayQueue::getTrack 0 Dec 01 00:06:20 rivoplus volumio[3429]: info: CoreStateMachine::startPlaybackTimer Dec 01 00:06:20 rivoplus volumio[3429]: info: CorePlayQueue::getTrack 0 Dec 01 00:06:20 rivoplus volumio[3429]: info: CoreCommandRouter::volumioGetVisibleSources Dec 01 00:06:20 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 01 00:06:20 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 01 00:06:20 rivoplus volumio[3429]: info: [1733004380331] ControllerWebradio::clearAddPlayTrack Dec 01 00:06:20 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand stop Dec 01 00:06:20 rivoplus volumio[3429]: info: sendMpdCommand stop took 2 milliseconds Dec 01 00:06:20 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand clear Dec 01 00:06:20 rivoplus volumio[3429]: info: Dec 01 00:06:20 rivoplus volumio[3429]: ---------------------------- MPD announces system playlist update Dec 01 00:06:20 rivoplus volumio[3429]: info: Ignoring MPD Status Update Dec 01 00:06:20 rivoplus volumio[3429]: info: sendMpdCommand clear took 5 milliseconds Dec 01 00:06:20 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=1677115" Dec 01 00:06:20 rivoplus volumio[3429]: error: updateQueue error: null Dec 01 00:06:20 rivoplus volumio[3429]: info: ------------------------------ 8ms Dec 01 00:06:21 rivoplus volumio[3429]: info: Dec 01 00:06:21 rivoplus volumio[3429]: ---------------------------- MPD announces system playlist update Dec 01 00:06:21 rivoplus volumio[3429]: info: Ignoring MPD Status Update Dec 01 00:06:21 rivoplus volumio[3429]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=1677115" took 1000 milliseconds Dec 01 00:06:21 rivoplus volumio[3429]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 01 00:06:21 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand play Dec 01 00:06:21 rivoplus volumio[3429]: info: ------------------------------ 7ms Dec 01 00:06:21 rivoplus volumio[3429]: info: sendMpdCommand play took 4 milliseconds Dec 01 00:06:22 rivoplus volumio[3429]: info: Executing endpoint metavolumio Dec 01 00:06:22 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 01 00:06:22 rivoplus volumio[3429]: info: Executing endpoint metavolumio Dec 01 00:06:22 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 01 00:06:22 rivoplus volumio[3429]: info: Dec 01 00:06:22 rivoplus volumio[3429]: ---------------------------- MPD announces state update: player Dec 01 00:06:22 rivoplus volumio[3429]: info: ControllerMpd::getState Dec 01 00:06:22 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand status Dec 01 00:06:22 rivoplus volumio[3429]: info: Dec 01 00:06:22 rivoplus volumio[3429]: ---------------------------- MPD announces system playlist update Dec 01 00:06:22 rivoplus volumio[3429]: info: Ignoring MPD Status Update Dec 01 00:06:22 rivoplus volumio[3429]: info: Dec 01 00:06:22 rivoplus volumio[3429]: ---------------------------- MPD announces state update: player Dec 01 00:06:22 rivoplus volumio[3429]: info: sendMpdCommand status took 90 milliseconds Dec 01 00:06:22 rivoplus volumio[3429]: info: ControllerMpd::getState Dec 01 00:06:22 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand status Dec 01 00:06:22 rivoplus volumio[3429]: verbose: ControllerMpd::parseState Dec 01 00:06:22 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 01 00:06:22 rivoplus volumio[3429]: info: ------------------------------ 13ms Dec 01 00:06:22 rivoplus volumio[3429]: info: sendMpdCommand status took 7 milliseconds Dec 01 00:06:22 rivoplus volumio[3429]: info: sendMpdCommand playlistinfo took 5 milliseconds Dec 01 00:06:22 rivoplus volumio[3429]: verbose: ControllerMpd::parseState Dec 01 00:06:22 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 01 00:06:22 rivoplus volumio[3429]: verbose: ControllerMpd::parseTrackInfo Dec 01 00:06:22 rivoplus volumio[3429]: info: ControllerMpd::pushState Dec 01 00:06:22 rivoplus volumio[3429]: info: CoreCommandRouter::servicePushState Dec 01 00:06:22 rivoplus volumio[3429]: info: CorePlayQueue::getTrack 0 Dec 01 00:06:22 rivoplus volumio[3429]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Katy Perry - Firework","artist":"1.FM - Cafe Radio","album":null,"uri":"http://185.33.21.112:80/caferadio_32a","trackType":""} Dec 01 00:06:22 rivoplus volumio[3429]: verbose: CURRENT POSITION 0 Dec 01 00:06:22 rivoplus volumio[3429]: info: CoreStateMachine::syncState stateService play Dec 01 00:06:22 rivoplus volumio[3429]: info: CoreStateMachine::syncState currentStatus stop Dec 01 00:06:22 rivoplus volumio[3429]: info: ------------------------------ 122ms Dec 01 00:06:22 rivoplus volumio[3429]: info: sendMpdCommand playlistinfo took 14 milliseconds Dec 01 00:06:22 rivoplus volumio[3429]: verbose: ControllerMpd::parseTrackInfo Dec 01 00:06:22 rivoplus volumio[3429]: info: ControllerMpd::pushState Dec 01 00:06:22 rivoplus volumio[3429]: info: CoreCommandRouter::servicePushState Dec 01 00:06:22 rivoplus volumio[3429]: info: CorePlayQueue::getTrack 0 Dec 01 00:06:22 rivoplus volumio[3429]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1232,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Katy Perry - Firework","artist":"1.FM - Cafe Radio","album":null,"uri":"http://185.33.21.112:80/caferadio_32a","trackType":""} Dec 01 00:06:22 rivoplus volumio[3429]: verbose: CURRENT POSITION 0 Dec 01 00:06:22 rivoplus volumio[3429]: info: CoreStateMachine::syncState stateService play Dec 01 00:06:22 rivoplus volumio[3429]: info: CoreStateMachine::syncState currentStatus play Dec 01 00:06:22 rivoplus volumio[3429]: info: Received an update from plugin. extracting info from payload Dec 01 00:06:22 rivoplus volumio[3429]: info: CoreStateMachine::pushState Dec 01 00:06:22 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 00:06:22 rivoplus volumio[3429]: info: CoreCommandRouter::volumioPushState Dec 01 00:06:22 rivoplus volumio[3429]: info: MRS: Pushing multiroomSync output update for this device Dec 01 00:06:22 rivoplus volumio[3429]: info: MRS: Pushing multiroomSync output Dec 01 00:06:22 rivoplus volumio[3429]: info: CoreStateMachine::pushState Dec 01 00:06:22 rivoplus volumio[3429]: info: CoreCommandRouter::volumioPushState Dec 01 00:06:22 rivoplus volumio[3429]: info: MRS: Pushing multiroomSync output update for this device Dec 01 00:06:22 rivoplus volumio[3429]: info: MRS: Pushing multiroomSync output Dec 01 00:06:22 rivoplus volumio[3429]: info: ------------------------------ 66ms Dec 01 00:06:22 rivoplus volumio[3429]: info: Signalling Playback active due to playback status change Dec 01 00:06:22 rivoplus volumio[3429]: info: Signalling Playback active due to playback status change Dec 01 00:06:22 rivoplus volumio[3429]: info: Updating RAAT Signal Path Dec 01 00:06:22 rivoplus volumio[3429]: info: MCU Signalled Playback Active Dec 01 00:06:24 rivoplus volumio[3429]: info: Executing endpoint metavolumio Dec 01 00:06:24 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 01 00:06:24 rivoplus volumio[3429]: info: Executing endpoint metavolumio Dec 01 00:06:24 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 01 00:06:25 rivoplus volumio[3429]: info: Dec 01 00:06:25 rivoplus volumio[3429]: ---------------------------- MPD announces system playlist update Dec 01 00:06:25 rivoplus volumio[3429]: info: Ignoring MPD Status Update Dec 01 00:06:25 rivoplus volumio[3429]: info: Dec 01 00:06:25 rivoplus volumio[3429]: ---------------------------- MPD announces state update: player Dec 01 00:06:25 rivoplus volumio[3429]: info: ControllerMpd::getState Dec 01 00:06:25 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand status Dec 01 00:06:25 rivoplus volumio[3429]: info: ------------------------------ 5ms Dec 01 00:06:25 rivoplus volumio[3429]: info: sendMpdCommand status took 6 milliseconds Dec 01 00:06:25 rivoplus volumio[3429]: verbose: ControllerMpd::parseState Dec 01 00:06:25 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 01 00:06:25 rivoplus volumio[3429]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 01 00:06:25 rivoplus volumio[3429]: verbose: ControllerMpd::parseTrackInfo Dec 01 00:06:25 rivoplus volumio[3429]: info: ControllerMpd::pushState Dec 01 00:06:25 rivoplus volumio[3429]: info: CoreCommandRouter::servicePushState Dec 01 00:06:25 rivoplus volumio[3429]: info: CorePlayQueue::getTrack 0 Dec 01 00:06:25 rivoplus volumio[3429]: verbose: STATE SERVICE {"status":"play","position":0,"seek":4112,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Olly Murs - Love You More","artist":"1.FM - Cafe Radio","album":null,"uri":"http://185.33.21.112:80/caferadio_32a","trackType":""} Dec 01 00:06:25 rivoplus volumio[3429]: verbose: CURRENT POSITION 0 Dec 01 00:06:25 rivoplus volumio[3429]: info: CoreStateMachine::syncState stateService play Dec 01 00:06:25 rivoplus volumio[3429]: info: CoreStateMachine::syncState currentStatus play Dec 01 00:06:25 rivoplus volumio[3429]: info: Received an update from plugin. extracting info from payload Dec 01 00:06:25 rivoplus volumio[3429]: info: CoreStateMachine::pushState Dec 01 00:06:25 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 00:06:25 rivoplus volumio[3429]: info: CoreCommandRouter::volumioPushState Dec 01 00:06:25 rivoplus volumio[3429]: info: MRS: Pushing multiroomSync output update for this device Dec 01 00:06:25 rivoplus volumio[3429]: info: MRS: Pushing multiroomSync output Dec 01 00:06:25 rivoplus volumio[3429]: info: CoreStateMachine::pushState Dec 01 00:06:25 rivoplus volumio[3429]: info: CoreCommandRouter::volumioPushState Dec 01 00:06:25 rivoplus volumio[3429]: info: MRS: Pushing multiroomSync output update for this device Dec 01 00:06:25 rivoplus volumio[3429]: info: MRS: Pushing multiroomSync output Dec 01 00:06:25 rivoplus volumio[3429]: info: ------------------------------ 46ms Dec 01 00:06:25 rivoplus volumio[3429]: info: Signalling Playback active due to playback status change Dec 01 00:06:25 rivoplus volumio[3429]: info: Signalling Playback active due to playback status change Dec 01 00:06:25 rivoplus volumio[3429]: info: Updating RAAT Signal Path Dec 01 00:06:25 rivoplus volumio[3429]: info: Updating RAAT Signal Path Dec 01 00:06:26 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 01 00:06:34 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 01 00:06:34 rivoplus volumio[3429]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Dec 01 00:06:34 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Dec 01 00:06:34 rivoplus volumio[3429]: info: Received Get System Version Dec 01 00:06:34 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 01 00:06:34 rivoplus volumio[3429]: info: Received Get System Info Dec 01 00:06:34 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 01 00:06:34 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 01 00:06:34 rivoplus volumio[3429]: info: Discovery: Getting this device information Dec 01 00:06:34 rivoplus volumio[3429]: info: CoreCommandRouter::volumioGetState Dec 01 00:06:34 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 01 00:06:42 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 01 00:06:42 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 01 00:06:42 rivoplus volumio[3429]: info: Discovery: Getting this device information Dec 01 00:06:42 rivoplus volumio[3429]: info: CoreCommandRouter::volumioGetState Dec 01 00:06:42 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 01 00:07:06 rivoplus volumio[3429]: info: Preload queue cleared Dec 01 00:07:06 rivoplus volumio[3429]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 01 00:07:06 rivoplus volumio[3429]: info: CoreStateMachine::ClearQueue Dec 01 00:07:06 rivoplus volumio[3429]: info: CoreStateMachine::stop Dec 01 00:07:06 rivoplus volumio[3429]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 01 00:07:06 rivoplus volumio[3429]: info: CoreStateMachine::stPlaybackTimer Dec 01 00:07:06 rivoplus volumio[3429]: info: CoreStateMachine::updateTrackBlock Dec 01 00:07:06 rivoplus volumio[3429]: info: CorePlayQueue::getTrackBlock Dec 01 00:07:06 rivoplus volumio[3429]: info: CoreStateMachine::pushState Dec 01 00:07:06 rivoplus volumio[3429]: info: CorePlayQueue::getTrack 0 Dec 01 00:07:06 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 00:07:06 rivoplus volumio[3429]: info: CoreCommandRouter::volumioPushState Dec 01 00:07:06 rivoplus volumio[3429]: info: MRS: Pushing multiroomSync output update for this device Dec 01 00:07:06 rivoplus volumio[3429]: info: MRS: Pushing multiroomSync output Dec 01 00:07:06 rivoplus volumio[3429]: info: CoreStateMachine::serviceStop Dec 01 00:07:06 rivoplus volumio[3429]: info: CorePlayQueue::getTrack 0 Dec 01 00:07:06 rivoplus volumio[3429]: info: CoreCommandRouter::serviceStop Dec 01 00:07:06 rivoplus volumio[3429]: info: [1733004426264] ControllerWebradio::stop Dec 01 00:07:06 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand stop Dec 01 00:07:06 rivoplus volumio[3429]: info: CorePlayQueue::clearPlayQueue Dec 01 00:07:06 rivoplus volumio[3429]: info: CorePlayQueue::saveQueue Dec 01 00:07:06 rivoplus volumio[3429]: info: CoreCommandRouter::volumioPushQueue Dec 01 00:07:06 rivoplus volumio[3429]: info: CoreStateMachine::addQueueItems Dec 01 00:07:06 rivoplus volumio[3429]: info: CorePlayQueue::addQueueItems Dec 01 00:07:06 rivoplus volumio[3429]: info: Preload queue cleared Dec 01 00:07:06 rivoplus volumio[3429]: info: Adding Item to queue: http://yp.shoutcast.com/sbin/tunein-station.m3u?id=1778139 Dec 01 00:07:06 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Dec 01 00:07:06 rivoplus volumio[3429]: info: CoreCommandRouter::volumioPushQueue Dec 01 00:07:06 rivoplus volumio[3429]: info: CorePlayQueue::saveQueue Dec 01 00:07:06 rivoplus volumio[3429]: info: CoreStateMachine::updateTrackBlock Dec 01 00:07:06 rivoplus volumio[3429]: info: CorePlayQueue::getTrackBlock Dec 01 00:07:06 rivoplus volumio[3429]: info: CoreCommandRouter::volumioPlay Dec 01 00:07:06 rivoplus volumio[3429]: info: CoreStateMachine::play index 0 Dec 01 00:07:06 rivoplus volumio[3429]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 01 00:07:06 rivoplus volumio[3429]: info: CoreStateMachine::stop Dec 01 00:07:06 rivoplus volumio[3429]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 01 00:07:06 rivoplus volumio[3429]: info: CoreStateMachine::play index undefined Dec 01 00:07:06 rivoplus volumio[3429]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 01 00:07:06 rivoplus volumio[3429]: info: CorePlayQueue::getTrack 0 Dec 01 00:07:06 rivoplus volumio[3429]: info: CoreStateMachine::startPlaybackTimer Dec 01 00:07:06 rivoplus volumio[3429]: info: CorePlayQueue::getTrack 0 Dec 01 00:07:06 rivoplus volumio[3429]: info: CoreCommandRouter::volumioGetVisibleSources Dec 01 00:07:06 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 01 00:07:06 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 01 00:07:06 rivoplus volumio[3429]: info: [1733004426300] ControllerWebradio::clearAddPlayTrack Dec 01 00:07:06 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand stop Dec 01 00:07:06 rivoplus volumio[3429]: info: Updating RAAT Signal Path Dec 01 00:07:06 rivoplus volumio[3429]: info: Dec 01 00:07:06 rivoplus volumio[3429]: ---------------------------- MPD announces state update: player Dec 01 00:07:06 rivoplus volumio[3429]: info: sendMpdCommand stop took 53 milliseconds Dec 01 00:07:06 rivoplus volumio[3429]: info: ControllerMpd::getState Dec 01 00:07:06 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand status Dec 01 00:07:06 rivoplus volumio[3429]: info: sendMpdCommand stop took 18 milliseconds Dec 01 00:07:06 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand clear Dec 01 00:07:06 rivoplus volumio[3429]: info: Dec 01 00:07:06 rivoplus volumio[3429]: ---------------------------- MPD announces system playlist update Dec 01 00:07:06 rivoplus volumio[3429]: info: Ignoring MPD Status Update Dec 01 00:07:06 rivoplus volumio[3429]: info: sendMpdCommand status took 19 milliseconds Dec 01 00:07:06 rivoplus volumio[3429]: info: sendMpdCommand clear took 18 milliseconds Dec 01 00:07:06 rivoplus volumio[3429]: verbose: ControllerMpd::parseState Dec 01 00:07:06 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 01 00:07:06 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=1778139" Dec 01 00:07:06 rivoplus volumio[3429]: info: MCU Signalled Playback Inactive Dec 01 00:07:06 rivoplus volumio[3429]: error: updateQueue error: null Dec 01 00:07:06 rivoplus volumio[3429]: info: Dec 01 00:07:06 rivoplus volumio[3429]: ---------------------------- MPD announces system playlist update Dec 01 00:07:06 rivoplus volumio[3429]: info: Ignoring MPD Status Update Dec 01 00:07:06 rivoplus volumio[3429]: info: ------------------------------ 144ms Dec 01 00:07:06 rivoplus volumio[3429]: info: sendMpdCommand playlistinfo took 140 milliseconds Dec 01 00:07:06 rivoplus volumio[3429]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=1778139" took 141 milliseconds Dec 01 00:07:06 rivoplus volumio[3429]: verbose: ControllerMpd::parseTrackInfo Dec 01 00:07:06 rivoplus volumio[3429]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 01 00:07:06 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand play Dec 01 00:07:06 rivoplus volumio[3429]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Dec 01 00:07:06 rivoplus volumio[3429]: info: ------------------------------ 172ms Dec 01 00:07:06 rivoplus volumio[3429]: info: ------------------------------ 10ms Dec 01 00:07:06 rivoplus volumio[3429]: info: sendMpdCommand play took 5 milliseconds Dec 01 00:07:07 rivoplus volumio[3429]: info: Dec 01 00:07:07 rivoplus volumio[3429]: ---------------------------- MPD announces state update: player Dec 01 00:07:07 rivoplus volumio[3429]: info: ControllerMpd::getState Dec 01 00:07:07 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand status Dec 01 00:07:07 rivoplus volumio[3429]: info: sendMpdCommand status took 24 milliseconds Dec 01 00:07:07 rivoplus volumio[3429]: verbose: ControllerMpd::parseState Dec 01 00:07:07 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 01 00:07:07 rivoplus volumio[3429]: info: Dec 01 00:07:07 rivoplus volumio[3429]: ---------------------------- MPD announces state update: player Dec 01 00:07:07 rivoplus volumio[3429]: info: ControllerMpd::getState Dec 01 00:07:07 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand status Dec 01 00:07:07 rivoplus volumio[3429]: info: sendMpdCommand playlistinfo took 3 milliseconds Dec 01 00:07:07 rivoplus volumio[3429]: verbose: ControllerMpd::parseTrackInfo Dec 01 00:07:07 rivoplus volumio[3429]: info: ControllerMpd::pushState Dec 01 00:07:07 rivoplus volumio[3429]: info: CoreCommandRouter::servicePushState Dec 01 00:07:07 rivoplus volumio[3429]: info: CorePlayQueue::getTrack 0 Dec 01 00:07:07 rivoplus volumio[3429]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"chilloutlounge_128","artist":"1.FM - Chillout Lounge (www.1.fm)","album":null,"uri":"http://185.33.21.112:80/chilloutlounge_128","trackType":""} Dec 01 00:07:07 rivoplus volumio[3429]: verbose: CURRENT POSITION 0 Dec 01 00:07:07 rivoplus volumio[3429]: info: CoreStateMachine::syncState stateService play Dec 01 00:07:07 rivoplus volumio[3429]: info: CoreStateMachine::syncState currentStatus stop Dec 01 00:07:07 rivoplus volumio[3429]: info: ------------------------------ 34ms Dec 01 00:07:07 rivoplus volumio[3429]: info: sendMpdCommand status took 6 milliseconds Dec 01 00:07:07 rivoplus volumio[3429]: verbose: ControllerMpd::parseState Dec 01 00:07:07 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 01 00:07:07 rivoplus volumio[3429]: info: sendMpdCommand playlistinfo took 2 milliseconds Dec 01 00:07:07 rivoplus volumio[3429]: verbose: ControllerMpd::parseTrackInfo Dec 01 00:07:07 rivoplus volumio[3429]: info: ControllerMpd::pushState Dec 01 00:07:07 rivoplus volumio[3429]: info: CoreCommandRouter::servicePushState Dec 01 00:07:07 rivoplus volumio[3429]: info: CorePlayQueue::getTrack 0 Dec 01 00:07:07 rivoplus volumio[3429]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"chilloutlounge_128","artist":"1.FM - Chillout Lounge (www.1.fm)","album":null,"uri":"http://185.33.21.112:80/chilloutlounge_128","trackType":""} Dec 01 00:07:07 rivoplus volumio[3429]: verbose: CURRENT POSITION 0 Dec 01 00:07:07 rivoplus volumio[3429]: info: CoreStateMachine::syncState stateService play Dec 01 00:07:07 rivoplus volumio[3429]: info: CoreStateMachine::syncState currentStatus play Dec 01 00:07:07 rivoplus volumio[3429]: info: Received an update from plugin. extracting info from payload Dec 01 00:07:07 rivoplus volumio[3429]: info: CoreStateMachine::pushState Dec 01 00:07:07 rivoplus volumio[3429]: info: CorePlayQueue::getTrack 0 Dec 01 00:07:07 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 00:07:07 rivoplus volumio[3429]: info: CoreCommandRouter::volumioPushState Dec 01 00:07:07 rivoplus volumio[3429]: info: MRS: Pushing multiroomSync output update for this device Dec 01 00:07:07 rivoplus volumio[3429]: info: MRS: Pushing multiroomSync output Dec 01 00:07:07 rivoplus volumio[3429]: info: CoreStateMachine::pushState Dec 01 00:07:07 rivoplus volumio[3429]: info: CoreCommandRouter::volumioPushState Dec 01 00:07:07 rivoplus volumio[3429]: info: MRS: Pushing multiroomSync output update for this device Dec 01 00:07:07 rivoplus volumio[3429]: info: MRS: Pushing multiroomSync output Dec 01 00:07:07 rivoplus volumio[3429]: info: ------------------------------ 46ms Dec 01 00:07:07 rivoplus volumio[3429]: info: Signalling Playback active due to playback status change Dec 01 00:07:07 rivoplus volumio[3429]: info: Signalling Playback active due to playback status change Dec 01 00:07:07 rivoplus volumio[3429]: info: Updating RAAT Signal Path Dec 01 00:07:07 rivoplus volumio[3429]: info: Updating RAAT Signal Path Dec 01 00:07:07 rivoplus volumio[3429]: info: Dec 01 00:07:07 rivoplus volumio[3429]: ---------------------------- MPD announces system playlist update Dec 01 00:07:07 rivoplus volumio[3429]: info: Ignoring MPD Status Update Dec 01 00:07:07 rivoplus volumio[3429]: info: Dec 01 00:07:07 rivoplus volumio[3429]: ---------------------------- MPD announces state update: player Dec 01 00:07:07 rivoplus volumio[3429]: info: ControllerMpd::getState Dec 01 00:07:07 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand status Dec 01 00:07:07 rivoplus volumio[3429]: info: Dec 01 00:07:07 rivoplus volumio[3429]: ---------------------------- MPD announces system playlist update Dec 01 00:07:07 rivoplus volumio[3429]: info: Ignoring MPD Status Update Dec 01 00:07:07 rivoplus volumio[3429]: info: Dec 01 00:07:07 rivoplus volumio[3429]: ---------------------------- MPD announces state update: player Dec 01 00:07:07 rivoplus volumio[3429]: info: ControllerMpd::getState Dec 01 00:07:07 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand status Dec 01 00:07:07 rivoplus volumio[3429]: info: ------------------------------ 8ms Dec 01 00:07:07 rivoplus volumio[3429]: info: sendMpdCommand status took 11 milliseconds Dec 01 00:07:07 rivoplus volumio[3429]: verbose: ControllerMpd::parseState Dec 01 00:07:07 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 01 00:07:07 rivoplus volumio[3429]: info: ------------------------------ 13ms Dec 01 00:07:07 rivoplus volumio[3429]: info: sendMpdCommand status took 11 milliseconds Dec 01 00:07:07 rivoplus volumio[3429]: info: sendMpdCommand playlistinfo took 4 milliseconds Dec 01 00:07:07 rivoplus volumio[3429]: verbose: ControllerMpd::parseState Dec 01 00:07:07 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 01 00:07:07 rivoplus volumio[3429]: verbose: ControllerMpd::parseTrackInfo Dec 01 00:07:07 rivoplus volumio[3429]: info: ControllerMpd::pushState Dec 01 00:07:07 rivoplus volumio[3429]: info: CoreCommandRouter::servicePushState Dec 01 00:07:07 rivoplus volumio[3429]: info: CorePlayQueue::getTrack 0 Dec 01 00:07:07 rivoplus volumio[3429]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1221,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Mysticage - The Lips Of The Sun (Original)","artist":"1.FM - Chillout Lounge Radio","album":null,"uri":"http://185.33.21.112:80/chilloutlounge_128","trackType":""} Dec 01 00:07:07 rivoplus volumio[3429]: verbose: CURRENT POSITION 0 Dec 01 00:07:07 rivoplus volumio[3429]: info: CoreStateMachine::syncState stateService play Dec 01 00:07:07 rivoplus volumio[3429]: info: CoreStateMachine::syncState currentStatus play Dec 01 00:07:07 rivoplus volumio[3429]: info: Received an update from plugin. extracting info from payload Dec 01 00:07:07 rivoplus volumio[3429]: info: CoreStateMachine::pushState Dec 01 00:07:07 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 00:07:07 rivoplus volumio[3429]: info: CoreCommandRouter::volumioPushState Dec 01 00:07:07 rivoplus volumio[3429]: info: MRS: Pushing multiroomSync output update for this device Dec 01 00:07:07 rivoplus volumio[3429]: info: MRS: Pushing multiroomSync output Dec 01 00:07:07 rivoplus volumio[3429]: info: CoreStateMachine::pushState Dec 01 00:07:07 rivoplus volumio[3429]: info: CoreCommandRouter::volumioPushState Dec 01 00:07:07 rivoplus volumio[3429]: info: MRS: Pushing multiroomSync output update for this device Dec 01 00:07:07 rivoplus volumio[3429]: info: MRS: Pushing multiroomSync output Dec 01 00:07:07 rivoplus volumio[3429]: info: ------------------------------ 71ms Dec 01 00:07:07 rivoplus volumio[3429]: info: sendMpdCommand playlistinfo took 53 milliseconds Dec 01 00:07:07 rivoplus volumio[3429]: verbose: ControllerMpd::parseTrackInfo Dec 01 00:07:07 rivoplus volumio[3429]: info: ControllerMpd::pushState Dec 01 00:07:07 rivoplus volumio[3429]: info: CoreCommandRouter::servicePushState Dec 01 00:07:07 rivoplus volumio[3429]: info: CorePlayQueue::getTrack 0 Dec 01 00:07:07 rivoplus volumio[3429]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1232,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Mysticage - The Lips Of The Sun (Original)","artist":"1.FM - Chillout Lounge Radio","album":null,"uri":"http://185.33.21.112:80/chilloutlounge_128","trackType":""} Dec 01 00:07:07 rivoplus volumio[3429]: verbose: CURRENT POSITION 0 Dec 01 00:07:07 rivoplus volumio[3429]: info: CoreStateMachine::syncState stateService play Dec 01 00:07:07 rivoplus volumio[3429]: info: CoreStateMachine::syncState currentStatus play Dec 01 00:07:07 rivoplus volumio[3429]: info: Received an update from plugin. extracting info from payload Dec 01 00:07:07 rivoplus volumio[3429]: info: CoreStateMachine::pushState Dec 01 00:07:07 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 00:07:07 rivoplus volumio[3429]: info: CoreCommandRouter::volumioPushState Dec 01 00:07:07 rivoplus volumio[3429]: info: MRS: Pushing multiroomSync output update for this device Dec 01 00:07:07 rivoplus volumio[3429]: info: MRS: Pushing multiroomSync output Dec 01 00:07:07 rivoplus volumio[3429]: info: CoreStateMachine::pushState Dec 01 00:07:07 rivoplus volumio[3429]: info: CoreCommandRouter::volumioPushState Dec 01 00:07:07 rivoplus volumio[3429]: info: MRS: Pushing multiroomSync output update for this device Dec 01 00:07:07 rivoplus volumio[3429]: info: MRS: Pushing multiroomSync output Dec 01 00:07:07 rivoplus volumio[3429]: info: ------------------------------ 125ms Dec 01 00:07:07 rivoplus volumio[3429]: info: Signalling Playback active due to playback status change Dec 01 00:07:07 rivoplus volumio[3429]: info: Signalling Playback active due to playback status change Dec 01 00:07:07 rivoplus volumio[3429]: info: Signalling Playback active due to playback status change Dec 01 00:07:07 rivoplus volumio[3429]: info: Signalling Playback active due to playback status change Dec 01 00:07:07 rivoplus volumio[3429]: info: Updating RAAT Signal Path Dec 01 00:07:07 rivoplus volumio[3429]: info: Updating RAAT Signal Path Dec 01 00:07:07 rivoplus volumio[3429]: info: Updating RAAT Signal Path Dec 01 00:07:07 rivoplus volumio[3429]: info: Updating RAAT Signal Path Dec 01 00:07:07 rivoplus volumio[3429]: info: MCU Signalled Playback Active Dec 01 00:07:09 rivoplus volumio[3429]: info: Executing endpoint metavolumio Dec 01 00:07:09 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 01 00:07:09 rivoplus volumio[3429]: info: Executing endpoint metavolumio Dec 01 00:07:09 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 01 00:07:12 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 01 00:07:12 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 01 00:07:12 rivoplus volumio[3429]: info: Discovery: Getting this device information Dec 01 00:07:12 rivoplus volumio[3429]: info: CoreCommandRouter::volumioGetState Dec 01 00:07:12 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 01 00:07:31 rivoplus volumio[3429]: info: CoreCommandRouter::volumioStop Dec 01 00:07:31 rivoplus volumio[3429]: info: CoreStateMachine::stop Dec 01 00:07:31 rivoplus volumio[3429]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 01 00:07:31 rivoplus volumio[3429]: info: CoreStateMachine::stPlaybackTimer Dec 01 00:07:31 rivoplus volumio[3429]: info: CoreStateMachine::updateTrackBlock Dec 01 00:07:31 rivoplus volumio[3429]: info: CorePlayQueue::getTrackBlock Dec 01 00:07:31 rivoplus volumio[3429]: info: CoreStateMachine::pushState Dec 01 00:07:31 rivoplus volumio[3429]: info: CorePlayQueue::getTrack 0 Dec 01 00:07:31 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 00:07:31 rivoplus volumio[3429]: info: CoreCommandRouter::volumioPushState Dec 01 00:07:31 rivoplus volumio[3429]: info: MRS: Pushing multiroomSync output update for this device Dec 01 00:07:31 rivoplus volumio[3429]: info: MRS: Pushing multiroomSync output Dec 01 00:07:31 rivoplus volumio[3429]: info: CoreStateMachine::serviceStop Dec 01 00:07:31 rivoplus volumio[3429]: info: CorePlayQueue::getTrack 0 Dec 01 00:07:31 rivoplus volumio[3429]: info: CoreCommandRouter::serviceStop Dec 01 00:07:31 rivoplus volumio[3429]: info: [1733004451467] ControllerWebradio::stop Dec 01 00:07:31 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand stop Dec 01 00:07:31 rivoplus volumio[3429]: info: Updating RAAT Signal Path Dec 01 00:07:31 rivoplus volumio[3429]: info: Dec 01 00:07:31 rivoplus volumio[3429]: ---------------------------- MPD announces state update: player Dec 01 00:07:31 rivoplus volumio[3429]: info: sendMpdCommand stop took 38 milliseconds Dec 01 00:07:31 rivoplus volumio[3429]: info: ControllerMpd::getState Dec 01 00:07:31 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand status Dec 01 00:07:31 rivoplus volumio[3429]: info: sendMpdCommand status took 1 milliseconds Dec 01 00:07:31 rivoplus volumio[3429]: verbose: ControllerMpd::parseState Dec 01 00:07:31 rivoplus volumio[3429]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 01 00:07:31 rivoplus volumio[3429]: info: sendMpdCommand playlistinfo took 2 milliseconds Dec 01 00:07:31 rivoplus volumio[3429]: verbose: ControllerMpd::parseTrackInfo Dec 01 00:07:31 rivoplus volumio[3429]: info: ControllerMpd::pushState Dec 01 00:07:31 rivoplus volumio[3429]: info: CoreCommandRouter::servicePushState Dec 01 00:07:31 rivoplus volumio[3429]: info: CoreStateMachine::pushState Dec 01 00:07:31 rivoplus volumio[3429]: info: CorePlayQueue::getTrack 0 Dec 01 00:07:31 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 00:07:31 rivoplus volumio[3429]: info: CoreCommandRouter::volumioPushState Dec 01 00:07:31 rivoplus volumio[3429]: info: MRS: Pushing multiroomSync output update for this device Dec 01 00:07:31 rivoplus volumio[3429]: info: MRS: Pushing multiroomSync output Dec 01 00:07:31 rivoplus volumio[3429]: info: CorePlayQueue::getTrack 0 Dec 01 00:07:31 rivoplus volumio[3429]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Dec 01 00:07:31 rivoplus volumio[3429]: info: ------------------------------ 35ms Dec 01 00:07:31 rivoplus volumio[3429]: info: Updating RAAT Signal Path Dec 01 00:07:31 rivoplus volumio[3429]: info: MCU Signalled Playback Inactive Dec 01 00:07:33 rivoplus volumio[3429]: info: Executing endpoint metavolumio Dec 01 00:07:33 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 01 00:07:33 rivoplus volumio[3429]: info: Executing endpoint metavolumio Dec 01 00:07:33 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 01 00:07:37 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 01 00:07:37 rivoplus volumio[3429]: info: Preload queue cleared Dec 01 00:07:39 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 01 00:07:39 rivoplus volumio[3429]: info: Preload queue cleared Dec 01 00:07:42 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 01 00:07:42 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 01 00:07:42 rivoplus volumio[3429]: info: Discovery: Getting this device information Dec 01 00:07:42 rivoplus volumio[3429]: info: CoreCommandRouter::volumioGetState Dec 01 00:07:42 rivoplus volumio[3429]: info: CorePlayQueue::getTrack 0 Dec 01 00:07:42 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 01 00:07:45 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 01 00:07:45 rivoplus volumio[3429]: info: Preload queue cleared Dec 01 00:07:51 rivoplus volumio[3429]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 01 00:07:51 rivoplus volumio[3429]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 01 00:07:51 rivoplus volumio[3429]: TypeError: Cannot read property 'length' of undefined Dec 01 00:07:51 rivoplus volumio[3429]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Dec 01 00:07:51 rivoplus volumio[3429]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Dec 01 00:07:51 rivoplus volumio[3429]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Dec 01 00:07:51 rivoplus volumio[3429]: at Parser.emit (events.js:400:28) Dec 01 00:07:51 rivoplus volumio[3429]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Dec 01 00:07:51 rivoplus volumio[3429]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Dec 01 00:07:51 rivoplus volumio[3429]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Dec 01 00:07:51 rivoplus volumio[3429]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Dec 01 00:07:51 rivoplus volumio[3429]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Dec 01 00:07:51 rivoplus volumio[3429]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Dec 01 00:07:51 rivoplus volumio[3429]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Dec 01 00:07:51 rivoplus volumio[3429]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Dec 01 00:07:51 rivoplus volumio[3429]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Dec 01 00:07:51 rivoplus volumio[3429]: at IncomingMessage.emit (events.js:412:35) Dec 01 00:07:51 rivoplus volumio[3429]: at endReadableNT (internal/streams/readable.js:1333:12) Dec 01 00:07:51 rivoplus volumio[3429]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Dec 01 00:07:51 rivoplus volumio[3429]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 01 00:07:52 rivoplus sudo[5642]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-12-01 00:06 Dec 01 00:07:52 rivoplus sudo[5642]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivoplus" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 06:24:00 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="a9e7f7cddbf07b638557a97b929dd627"