May 15 20:40:01 volumiopi systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... May 15 20:40:01 volumiopi dbus-daemon[689]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.62' (uid=0 pid=3871 comm="timedatectl show --property=NTPSynchronized --valu") May 15 20:40:01 volumiopi systemd[1]: Starting systemd-timedated.service - Time & Date Service... May 15 20:40:01 volumiopi dbus-daemon[689]: [system] Successfully activated service 'org.freedesktop.timedate1' May 15 20:40:01 volumiopi systemd[1]: Started systemd-timedated.service - Time & Date Service. May 15 20:40:01 volumiopi setdatetime-helper.sh[3870]: Time is not synchronized. Attempting to sync... May 15 20:40:01 volumiopi sudo[3879]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Thu, 15 May 2025 18:40:02 GMT#015' May 15 20:40:01 volumiopi sudo[3879]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 15 20:40:02 volumiopi setdatetime-helper.sh[3880]: Thu May 15 20:40:02 CEST 2025 May 15 20:40:02 volumiopi sudo[3879]: pam_unix(sudo:session): session closed for user root May 15 20:40:02 volumiopi setdatetime-helper.sh[3870]: Time synchronized successfully. May 15 20:40:02 volumiopi systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. May 15 20:40:02 volumiopi systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. May 15 20:40:02 volumiopi volumio[1144]: info: Removing uri http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99501608 from favourites May 15 20:40:02 volumiopi volumio[1144]: info: Saving Cloud item radio-favourites May 15 20:40:02 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: my_volumio , saveCloudItem May 15 20:40:06 volumiopi volumio[1144]: info: CoreCommandRouter::volumioGetState May 15 20:40:06 volumiopi sudo[3883]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 15 20:40:06 volumiopi sudo[3883]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 15 20:40:06 volumiopi sudo[3883]: pam_unix(sudo:session): session closed for user root May 15 20:40:06 volumiopi sudo[3885]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 15 20:40:06 volumiopi sudo[3885]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 15 20:40:06 volumiopi sudo[3885]: pam_unix(sudo:session): session closed for user root May 15 20:40:06 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 15 20:40:06 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 15 20:40:06 volumiopi volumio[1144]: info: Discovery: Getting this device information May 15 20:40:06 volumiopi volumio[1144]: info: CoreCommandRouter::volumioGetState May 15 20:40:06 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 15 20:40:06 volumiopi volumio[1144]: verbose: New Socket.io Connection to 192.168.178.39 from 192.168.178.21 UA: Mozilla/5.0 (Linux; Android 12; LM-V500 Build/SKQ1.211103.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/135.0.7049.111 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 May 15 20:40:07 volumiopi sudo[3889]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 15 20:40:07 volumiopi sudo[3889]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 15 20:40:07 volumiopi sudo[3889]: pam_unix(sudo:session): session closed for user root May 15 20:40:07 volumiopi sudo[3891]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 15 20:40:07 volumiopi sudo[3891]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 15 20:40:07 volumiopi sudo[3891]: pam_unix(sudo:session): session closed for user root May 15 20:40:07 volumiopi volumio[1144]: verbose: New Socket.io Connection to 192.168.178.39 from 192.168.178.21 UA: Mozilla/5.0 (Linux; Android 12; LM-V500 Build/SKQ1.211103.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/135.0.7049.111 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 May 15 20:40:07 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 15 20:40:07 volumiopi volumio[1144]: info: CoreCommandRouter::volumioGetVisibleSources May 15 20:40:07 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 15 20:40:07 volumiopi volumio[1144]: info: CoreCommandRouter::volumioGetState May 15 20:40:07 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 15 20:40:07 volumiopi volumio[1144]: info: CoreCommandRouter::volumioGetQueue May 15 20:40:07 volumiopi volumio[1144]: info: CoreStateMachine::getQueue May 15 20:40:07 volumiopi volumio[1144]: info: CorePlayQueue::getQueue May 15 20:40:07 volumiopi volumio[1144]: info: Listing playlists May 15 20:40:07 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 15 20:40:07 volumiopi volumio[1144]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom May 15 20:40:07 volumiopi volumio[1144]: info: Received Get System Info May 15 20:40:07 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 15 20:40:07 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 15 20:40:07 volumiopi volumio[1144]: info: Discovery: Getting this device information May 15 20:40:07 volumiopi volumio[1144]: info: CoreCommandRouter::volumioGetState May 15 20:40:07 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 15 20:40:07 volumiopi volumio[1144]: info: CoreCommandRouter::volumioGetState May 15 20:40:07 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 15 20:40:07 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 15 20:40:07 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 15 20:40:09 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 15 20:40:09 volumiopi volumio[1144]: info: Received Get System Info May 15 20:40:09 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 15 20:40:09 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 15 20:40:09 volumiopi volumio[1144]: info: Discovery: Getting this device information May 15 20:40:09 volumiopi volumio[1144]: info: CoreCommandRouter::volumioGetState May 15 20:40:09 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 15 20:40:09 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard May 15 20:40:10 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 15 20:40:10 volumiopi volumio[1144]: info: Received Get System Info May 15 20:40:10 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 15 20:40:10 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 15 20:40:10 volumiopi volumio[1144]: info: Discovery: Getting this device information May 15 20:40:10 volumiopi volumio[1144]: info: CoreCommandRouter::volumioGetState May 15 20:40:10 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 15 20:40:13 volumiopi volumio[1144]: info: Preload queue cleared May 15 20:40:13 volumiopi volumio[1144]: info: CoreCommandRouter::volumioReplaceandPlayItems May 15 20:40:13 volumiopi volumio[1144]: info: CoreStateMachine::ClearQueue May 15 20:40:13 volumiopi volumio[1144]: info: CoreStateMachine::stop May 15 20:40:13 volumiopi volumio[1144]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 20:40:13 volumiopi volumio[1144]: info: CorePlayQueue::clearPlayQueue May 15 20:40:13 volumiopi volumio[1144]: info: CorePlayQueue::saveQueue May 15 20:40:13 volumiopi volumio[1144]: info: CoreCommandRouter::volumioPushQueue May 15 20:40:13 volumiopi volumio[1144]: info: CoreStateMachine::addQueueItems May 15 20:40:13 volumiopi volumio[1144]: info: CorePlayQueue::addQueueItems May 15 20:40:13 volumiopi volumio[1144]: info: Preload queue cleared May 15 20:40:13 volumiopi volumio[1144]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s74983 May 15 20:40:13 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri May 15 20:40:14 volumiopi volumio[1144]: info: CoreCommandRouter::volumioPushQueue May 15 20:40:14 volumiopi volumio[1144]: info: CorePlayQueue::saveQueue May 15 20:40:14 volumiopi volumio[1144]: info: CoreStateMachine::updateTrackBlock May 15 20:40:14 volumiopi volumio[1144]: info: CorePlayQueue::getTrackBlock May 15 20:40:14 volumiopi volumio[1144]: info: CoreCommandRouter::volumioPlay May 15 20:40:14 volumiopi volumio[1144]: info: CoreStateMachine::play index 0 May 15 20:40:14 volumiopi volumio[1144]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 20:40:14 volumiopi volumio[1144]: info: CoreStateMachine::stop May 15 20:40:14 volumiopi volumio[1144]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 20:40:14 volumiopi volumio[1144]: info: CoreStateMachine::play index undefined May 15 20:40:14 volumiopi volumio[1144]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 20:40:14 volumiopi volumio[1144]: info: CorePlayQueue::getTrack 0 May 15 20:40:14 volumiopi volumio[1144]: info: CoreStateMachine::startPlaybackTimer May 15 20:40:14 volumiopi volumio[1144]: info: CorePlayQueue::getTrack 0 May 15 20:40:14 volumiopi volumio[1144]: info: CoreCommandRouter::volumioGetVisibleSources May 15 20:40:14 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 15 20:40:14 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 15 20:40:14 volumiopi volumio[1144]: info: [1747334414613] ControllerWebradio::clearAddPlayTrack May 15 20:40:14 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand stop May 15 20:40:14 volumiopi volumio[1144]: info: sendMpdCommand stop took 3 milliseconds May 15 20:40:14 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand clear May 15 20:40:14 volumiopi volumio[1144]: info: May 15 20:40:14 volumiopi volumio[1144]: ---------------------------- MPD announces system playlist update May 15 20:40:14 volumiopi volumio[1144]: info: Ignoring MPD Status Update May 15 20:40:14 volumiopi volumio[1144]: info: sendMpdCommand clear took 1 milliseconds May 15 20:40:14 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand load "http://www.1.fm/tunestream/80s_90s/listen.pls" May 15 20:40:14 volumiopi volumio[1144]: error: updateQueue error: null May 15 20:40:14 volumiopi volumio[1144]: info: ------------------------------ 1ms May 15 20:40:16 volumiopi volumio[1144]: info: May 15 20:40:16 volumiopi volumio[1144]: ---------------------------- MPD announces system playlist update May 15 20:40:16 volumiopi volumio[1144]: info: Ignoring MPD Status Update May 15 20:40:16 volumiopi volumio[1144]: info: sendMpdCommand load "http://www.1.fm/tunestream/80s_90s/listen.pls" took 1730 milliseconds May 15 20:40:16 volumiopi volumio[1144]: info: CoreStateMachine::setConsumeUpdateService mpd May 15 20:40:16 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand play May 15 20:40:16 volumiopi volumio[1144]: info: ------------------------------ 1ms May 15 20:40:16 volumiopi volumio[1144]: info: sendMpdCommand play took 1 milliseconds May 15 20:40:17 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 20:40:19 volumiopi volumio[1144]: info: May 15 20:40:19 volumiopi volumio[1144]: ---------------------------- MPD announces state update: player May 15 20:40:19 volumiopi volumio[1144]: info: ControllerMpd::getState May 15 20:40:19 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand status May 15 20:40:19 volumiopi volumio[1144]: info: May 15 20:40:19 volumiopi volumio[1144]: ---------------------------- MPD announces state update: player May 15 20:40:19 volumiopi volumio[1144]: info: sendMpdCommand status took 10 milliseconds May 15 20:40:19 volumiopi volumio[1144]: info: ControllerMpd::getState May 15 20:40:19 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand status May 15 20:40:19 volumiopi volumio[1144]: verbose: ControllerMpd::parseState May 15 20:40:19 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 20:40:19 volumiopi volumio[1144]: info: sendMpdCommand status took 1 milliseconds May 15 20:40:19 volumiopi volumio[1144]: info: sendMpdCommand playlistinfo took 1 milliseconds May 15 20:40:19 volumiopi volumio[1144]: verbose: ControllerMpd::parseState May 15 20:40:19 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 20:40:19 volumiopi volumio[1144]: verbose: ControllerMpd::parseTrackInfo May 15 20:40:19 volumiopi volumio[1144]: info: ControllerMpd::pushState May 15 20:40:19 volumiopi volumio[1144]: info: CoreCommandRouter::servicePushState May 15 20:40:19 volumiopi volumio[1144]: info: CorePlayQueue::getTrack 0 May 15 20:40:19 volumiopi volumio[1144]: 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":"All Euro 80's Radio","artist":null,"album":null,"uri":"http://strm112.1.fm:80/80s_90s_mobile_mp3","trackType":""} May 15 20:40:19 volumiopi volumio[1144]: verbose: CURRENT POSITION 0 May 15 20:40:19 volumiopi volumio[1144]: info: CoreStateMachine::syncState stateService play May 15 20:40:19 volumiopi volumio[1144]: info: CoreStateMachine::syncState currentStatus stop May 15 20:40:19 volumiopi volumio[1144]: info: ------------------------------ 13ms May 15 20:40:19 volumiopi volumio[1144]: info: sendMpdCommand playlistinfo took 4 milliseconds May 15 20:40:19 volumiopi volumio[1144]: verbose: ControllerMpd::parseTrackInfo May 15 20:40:19 volumiopi volumio[1144]: info: ControllerMpd::pushState May 15 20:40:19 volumiopi volumio[1144]: info: CoreCommandRouter::servicePushState May 15 20:40:19 volumiopi volumio[1144]: info: CorePlayQueue::getTrack 0 May 15 20:40:19 volumiopi volumio[1144]: 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":"All Euro 80's Radio","artist":null,"album":null,"uri":"http://strm112.1.fm:80/80s_90s_mobile_mp3","trackType":""} May 15 20:40:19 volumiopi volumio[1144]: verbose: CURRENT POSITION 0 May 15 20:40:19 volumiopi volumio[1144]: info: CoreStateMachine::syncState stateService play May 15 20:40:19 volumiopi volumio[1144]: info: CoreStateMachine::syncState currentStatus play May 15 20:40:19 volumiopi volumio[1144]: info: Received an update from plugin. extracting info from payload May 15 20:40:19 volumiopi volumio[1144]: info: CoreStateMachine::pushState May 15 20:40:19 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 20:40:19 volumiopi volumio[1144]: info: CoreCommandRouter::volumioPushState May 15 20:40:19 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output update for this device May 15 20:40:19 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output May 15 20:40:19 volumiopi volumio[1144]: info: CoreStateMachine::pushState May 15 20:40:19 volumiopi volumio[1144]: info: CoreCommandRouter::volumioPushState May 15 20:40:19 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output update for this device May 15 20:40:19 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output May 15 20:40:19 volumiopi volumio[1144]: info: ------------------------------ 41ms May 15 20:40:19 volumiopi volumio[1144]: info: May 15 20:40:19 volumiopi volumio[1144]: ---------------------------- MPD announces system playlist update May 15 20:40:19 volumiopi volumio[1144]: info: Ignoring MPD Status Update May 15 20:40:19 volumiopi volumio[1144]: info: May 15 20:40:19 volumiopi volumio[1144]: ---------------------------- MPD announces state update: player May 15 20:40:19 volumiopi volumio[1144]: info: ControllerMpd::getState May 15 20:40:19 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand status May 15 20:40:19 volumiopi volumio[1144]: info: ------------------------------ 2ms May 15 20:40:19 volumiopi volumio[1144]: info: sendMpdCommand status took 2 milliseconds May 15 20:40:19 volumiopi volumio[1144]: verbose: ControllerMpd::parseState May 15 20:40:19 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 20:40:19 volumiopi volumio[1144]: info: sendMpdCommand playlistinfo took 1 milliseconds May 15 20:40:19 volumiopi volumio[1144]: verbose: ControllerMpd::parseTrackInfo May 15 20:40:19 volumiopi volumio[1144]: info: ControllerMpd::pushState May 15 20:40:19 volumiopi volumio[1144]: info: CoreCommandRouter::servicePushState May 15 20:40:19 volumiopi volumio[1144]: info: CorePlayQueue::getTrack 0 May 15 20:40:19 volumiopi volumio[1144]: verbose: STATE SERVICE {"status":"play","position":0,"seek":541,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Righeira - Vamos A La Playa","artist":"80s_90s","album":null,"uri":"http://strm112.1.fm:80/80s_90s_mobile_mp3","trackType":""} May 15 20:40:19 volumiopi volumio[1144]: verbose: CURRENT POSITION 0 May 15 20:40:19 volumiopi volumio[1144]: info: CoreStateMachine::syncState stateService play May 15 20:40:19 volumiopi volumio[1144]: info: CoreStateMachine::syncState currentStatus play May 15 20:40:19 volumiopi volumio[1144]: info: Received an update from plugin. extracting info from payload May 15 20:40:19 volumiopi volumio[1144]: info: CoreStateMachine::pushState May 15 20:40:19 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 20:40:19 volumiopi volumio[1144]: info: CoreCommandRouter::volumioPushState May 15 20:40:19 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output update for this device May 15 20:40:19 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output May 15 20:40:19 volumiopi volumio[1144]: info: CoreStateMachine::pushState May 15 20:40:19 volumiopi volumio[1144]: info: CoreCommandRouter::volumioPushState May 15 20:40:19 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output update for this device May 15 20:40:19 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output May 15 20:40:19 volumiopi volumio[1144]: info: ------------------------------ 28ms May 15 20:40:25 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 15 20:40:25 volumiopi volumio[1144]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined May 15 20:40:25 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates May 15 20:40:25 volumiopi volumio[1144]: info: Received Get System Version May 15 20:40:25 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 15 20:40:25 volumiopi volumio[1144]: info: Received Get System Info May 15 20:40:25 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 15 20:40:25 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 15 20:40:25 volumiopi volumio[1144]: info: Discovery: Getting this device information May 15 20:40:25 volumiopi volumio[1144]: info: CoreCommandRouter::volumioGetState May 15 20:40:25 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 15 20:40:25 volumiopi volumio[1144]: info: Preload queue cleared May 15 20:40:25 volumiopi volumio[1144]: info: CoreCommandRouter::volumioReplaceandPlayItems May 15 20:40:25 volumiopi volumio[1144]: info: CoreStateMachine::ClearQueue May 15 20:40:25 volumiopi volumio[1144]: info: CoreStateMachine::stop May 15 20:40:25 volumiopi volumio[1144]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 20:40:25 volumiopi volumio[1144]: info: CoreStateMachine::stPlaybackTimer May 15 20:40:25 volumiopi volumio[1144]: info: CoreStateMachine::updateTrackBlock May 15 20:40:25 volumiopi volumio[1144]: info: CorePlayQueue::getTrackBlock May 15 20:40:25 volumiopi volumio[1144]: info: CoreStateMachine::pushState May 15 20:40:25 volumiopi volumio[1144]: info: CorePlayQueue::getTrack 0 May 15 20:40:25 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 20:40:25 volumiopi volumio[1144]: info: CoreCommandRouter::volumioPushState May 15 20:40:25 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output update for this device May 15 20:40:25 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output May 15 20:40:25 volumiopi volumio[1144]: info: CoreStateMachine::serviceStop May 15 20:40:25 volumiopi volumio[1144]: info: CorePlayQueue::getTrack 0 May 15 20:40:25 volumiopi volumio[1144]: info: CoreCommandRouter::serviceStop May 15 20:40:25 volumiopi volumio[1144]: info: [1747334425625] ControllerWebradio::stop May 15 20:40:25 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand stop May 15 20:40:25 volumiopi volumio[1144]: info: CorePlayQueue::clearPlayQueue May 15 20:40:25 volumiopi volumio[1144]: info: CorePlayQueue::saveQueue May 15 20:40:25 volumiopi volumio[1144]: info: CoreCommandRouter::volumioPushQueue May 15 20:40:25 volumiopi volumio[1144]: info: CoreStateMachine::addQueueItems May 15 20:40:25 volumiopi volumio[1144]: info: CorePlayQueue::addQueueItems May 15 20:40:25 volumiopi volumio[1144]: info: Preload queue cleared May 15 20:40:25 volumiopi volumio[1144]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s74984 May 15 20:40:25 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri May 15 20:40:25 volumiopi volumio[1144]: info: May 15 20:40:25 volumiopi volumio[1144]: ---------------------------- MPD announces state update: player May 15 20:40:25 volumiopi volumio[1144]: info: sendMpdCommand stop took 40 milliseconds May 15 20:40:25 volumiopi volumio[1144]: info: ControllerMpd::getState May 15 20:40:25 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand status May 15 20:40:25 volumiopi volumio[1144]: info: sendMpdCommand status took 1 milliseconds May 15 20:40:25 volumiopi volumio[1144]: verbose: ControllerMpd::parseState May 15 20:40:25 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 20:40:25 volumiopi volumio[1144]: info: sendMpdCommand playlistinfo took 0 milliseconds May 15 20:40:25 volumiopi volumio[1144]: verbose: ControllerMpd::parseTrackInfo May 15 20:40:25 volumiopi volumio[1144]: info: ControllerMpd::pushState May 15 20:40:25 volumiopi volumio[1144]: info: CoreCommandRouter::servicePushState May 15 20:40:25 volumiopi volumio[1144]: info: CoreStateMachine::pushState May 15 20:40:25 volumiopi volumio[1144]: info: CorePlayQueue::getTrack 0 May 15 20:40:25 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 20:40:25 volumiopi volumio[1144]: info: CoreCommandRouter::volumioPushState May 15 20:40:25 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output update for this device May 15 20:40:25 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output May 15 20:40:25 volumiopi volumio[1144]: info: CorePlayQueue::getTrack 0 May 15 20:40:25 volumiopi volumio[1144]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Righeira - Vamos A La Playa","artist":"80s_90s","album":null,"uri":"http://strm112.1.fm:80/80s_90s_mobile_mp3","trackType":""} May 15 20:40:25 volumiopi volumio[1144]: verbose: CURRENT POSITION 0 May 15 20:40:25 volumiopi volumio[1144]: info: CoreStateMachine::syncState stateService stop May 15 20:40:25 volumiopi volumio[1144]: info: CoreStateMachine::syncState currentStatus stop May 15 20:40:25 volumiopi volumio[1144]: info: CoreStateMachine::pushState May 15 20:40:25 volumiopi volumio[1144]: info: CorePlayQueue::getTrack 0 May 15 20:40:25 volumiopi volumio[1144]: info: CoreCommandRouter::volumioPushState May 15 20:40:25 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output update for this device May 15 20:40:25 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output May 15 20:40:25 volumiopi volumio[1144]: info: No code May 15 20:40:25 volumiopi volumio[1144]: info: CoreStateMachine::pushState May 15 20:40:25 volumiopi volumio[1144]: info: CorePlayQueue::getTrack 0 May 15 20:40:25 volumiopi volumio[1144]: info: CoreCommandRouter::volumioPushState May 15 20:40:25 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output update for this device May 15 20:40:25 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output May 15 20:40:25 volumiopi volumio[1144]: info: ------------------------------ 45ms May 15 20:40:25 volumiopi volumio[1144]: info: CoreCommandRouter::volumioPushQueue May 15 20:40:25 volumiopi volumio[1144]: info: CorePlayQueue::saveQueue May 15 20:40:25 volumiopi volumio[1144]: info: CoreStateMachine::updateTrackBlock May 15 20:40:25 volumiopi volumio[1144]: info: CorePlayQueue::getTrackBlock May 15 20:40:25 volumiopi volumio[1144]: info: CoreCommandRouter::volumioPlay May 15 20:40:25 volumiopi volumio[1144]: info: CoreStateMachine::play index 0 May 15 20:40:25 volumiopi volumio[1144]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 20:40:25 volumiopi volumio[1144]: info: CoreStateMachine::stop May 15 20:40:25 volumiopi volumio[1144]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 20:40:25 volumiopi volumio[1144]: info: CoreStateMachine::play index undefined May 15 20:40:25 volumiopi volumio[1144]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 20:40:25 volumiopi volumio[1144]: info: CorePlayQueue::getTrack 0 May 15 20:40:25 volumiopi volumio[1144]: info: CoreStateMachine::startPlaybackTimer May 15 20:40:25 volumiopi volumio[1144]: info: CorePlayQueue::getTrack 0 May 15 20:40:25 volumiopi volumio[1144]: info: CoreCommandRouter::volumioGetVisibleSources May 15 20:40:25 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 15 20:40:25 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 15 20:40:25 volumiopi volumio[1144]: info: [1747334425951] ControllerWebradio::clearAddPlayTrack May 15 20:40:25 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand stop May 15 20:40:25 volumiopi volumio[1144]: info: sendMpdCommand stop took 2 milliseconds May 15 20:40:25 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand clear May 15 20:40:25 volumiopi volumio[1144]: info: May 15 20:40:25 volumiopi volumio[1144]: ---------------------------- MPD announces system playlist update May 15 20:40:25 volumiopi volumio[1144]: info: Ignoring MPD Status Update May 15 20:40:25 volumiopi volumio[1144]: info: sendMpdCommand clear took 1 milliseconds May 15 20:40:25 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand load "http://www.1.fm/tunestream/back280s/listen.pls" May 15 20:40:25 volumiopi volumio[1144]: error: updateQueue error: null May 15 20:40:25 volumiopi volumio[1144]: info: ------------------------------ 1ms May 15 20:40:26 volumiopi volumio[1144]: info: May 15 20:40:26 volumiopi volumio[1144]: ---------------------------- MPD announces system playlist update May 15 20:40:26 volumiopi volumio[1144]: info: Ignoring MPD Status Update May 15 20:40:26 volumiopi volumio[1144]: info: sendMpdCommand load "http://www.1.fm/tunestream/back280s/listen.pls" took 123 milliseconds May 15 20:40:26 volumiopi volumio[1144]: info: CoreStateMachine::setConsumeUpdateService mpd May 15 20:40:26 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand play May 15 20:40:26 volumiopi volumio[1144]: info: ------------------------------ 2ms May 15 20:40:26 volumiopi volumio[1144]: info: sendMpdCommand play took 1 milliseconds May 15 20:40:28 volumiopi volumio[1144]: info: May 15 20:40:28 volumiopi volumio[1144]: ---------------------------- MPD announces state update: player May 15 20:40:28 volumiopi volumio[1144]: info: ControllerMpd::getState May 15 20:40:28 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand status May 15 20:40:28 volumiopi volumio[1144]: info: May 15 20:40:28 volumiopi volumio[1144]: ---------------------------- MPD announces state update: player May 15 20:40:28 volumiopi volumio[1144]: info: sendMpdCommand status took 6 milliseconds May 15 20:40:28 volumiopi volumio[1144]: info: ControllerMpd::getState May 15 20:40:28 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand status May 15 20:40:28 volumiopi volumio[1144]: verbose: ControllerMpd::parseState May 15 20:40:28 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 20:40:28 volumiopi volumio[1144]: info: sendMpdCommand status took 1 milliseconds May 15 20:40:28 volumiopi volumio[1144]: info: sendMpdCommand playlistinfo took 1 milliseconds May 15 20:40:28 volumiopi volumio[1144]: verbose: ControllerMpd::parseState May 15 20:40:28 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 20:40:28 volumiopi volumio[1144]: verbose: ControllerMpd::parseTrackInfo May 15 20:40:28 volumiopi volumio[1144]: info: ControllerMpd::pushState May 15 20:40:28 volumiopi volumio[1144]: info: CoreCommandRouter::servicePushState May 15 20:40:28 volumiopi volumio[1144]: info: CorePlayQueue::getTrack 0 May 15 20:40:28 volumiopi volumio[1144]: 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":"A List 80s","artist":null,"album":null,"uri":"http://strm112.1.fm:80/back280s_mobile_mp3","trackType":""} May 15 20:40:28 volumiopi volumio[1144]: verbose: CURRENT POSITION 0 May 15 20:40:28 volumiopi volumio[1144]: info: CoreStateMachine::syncState stateService play May 15 20:40:28 volumiopi volumio[1144]: info: CoreStateMachine::syncState currentStatus stop May 15 20:40:28 volumiopi volumio[1144]: info: ------------------------------ 9ms May 15 20:40:28 volumiopi volumio[1144]: info: sendMpdCommand playlistinfo took 1 milliseconds May 15 20:40:28 volumiopi volumio[1144]: verbose: ControllerMpd::parseTrackInfo May 15 20:40:28 volumiopi volumio[1144]: info: ControllerMpd::pushState May 15 20:40:28 volumiopi volumio[1144]: info: CoreCommandRouter::servicePushState May 15 20:40:28 volumiopi volumio[1144]: info: CorePlayQueue::getTrack 0 May 15 20:40:28 volumiopi volumio[1144]: 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":"A List 80s","artist":null,"album":null,"uri":"http://strm112.1.fm:80/back280s_mobile_mp3","trackType":""} May 15 20:40:28 volumiopi volumio[1144]: verbose: CURRENT POSITION 0 May 15 20:40:28 volumiopi volumio[1144]: info: CoreStateMachine::syncState stateService play May 15 20:40:28 volumiopi volumio[1144]: info: CoreStateMachine::syncState currentStatus play May 15 20:40:28 volumiopi volumio[1144]: info: Received an update from plugin. extracting info from payload May 15 20:40:28 volumiopi volumio[1144]: info: CoreStateMachine::pushState May 15 20:40:28 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 20:40:28 volumiopi volumio[1144]: info: CoreCommandRouter::volumioPushState May 15 20:40:28 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output update for this device May 15 20:40:28 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output May 15 20:40:28 volumiopi volumio[1144]: info: CoreStateMachine::pushState May 15 20:40:28 volumiopi volumio[1144]: info: CoreCommandRouter::volumioPushState May 15 20:40:28 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output update for this device May 15 20:40:28 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output May 15 20:40:28 volumiopi volumio[1144]: info: ------------------------------ 44ms May 15 20:40:28 volumiopi volumio[1144]: info: May 15 20:40:28 volumiopi volumio[1144]: ---------------------------- MPD announces system playlist update May 15 20:40:28 volumiopi volumio[1144]: info: Ignoring MPD Status Update May 15 20:40:28 volumiopi volumio[1144]: info: May 15 20:40:28 volumiopi volumio[1144]: ---------------------------- MPD announces state update: player May 15 20:40:28 volumiopi volumio[1144]: info: ControllerMpd::getState May 15 20:40:28 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand status May 15 20:40:28 volumiopi volumio[1144]: info: ------------------------------ 14ms May 15 20:40:28 volumiopi volumio[1144]: info: sendMpdCommand status took 14 milliseconds May 15 20:40:28 volumiopi volumio[1144]: verbose: ControllerMpd::parseState May 15 20:40:28 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 20:40:28 volumiopi volumio[1144]: info: sendMpdCommand playlistinfo took 2 milliseconds May 15 20:40:28 volumiopi volumio[1144]: verbose: ControllerMpd::parseTrackInfo May 15 20:40:28 volumiopi volumio[1144]: info: ControllerMpd::pushState May 15 20:40:28 volumiopi volumio[1144]: info: CoreCommandRouter::servicePushState May 15 20:40:28 volumiopi volumio[1144]: info: CorePlayQueue::getTrack 0 May 15 20:40:28 volumiopi volumio[1144]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1205,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Joy Division - Atmosphere","artist":"1.FM - A List 80s","album":null,"uri":"http://strm112.1.fm:80/back280s_mobile_mp3","trackType":""} May 15 20:40:28 volumiopi volumio[1144]: verbose: CURRENT POSITION 0 May 15 20:40:28 volumiopi volumio[1144]: info: CoreStateMachine::syncState stateService play May 15 20:40:28 volumiopi volumio[1144]: info: CoreStateMachine::syncState currentStatus play May 15 20:40:28 volumiopi volumio[1144]: info: Received an update from plugin. extracting info from payload May 15 20:40:28 volumiopi volumio[1144]: info: CoreStateMachine::pushState May 15 20:40:28 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 20:40:28 volumiopi volumio[1144]: info: CoreCommandRouter::volumioPushState May 15 20:40:28 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output update for this device May 15 20:40:28 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output May 15 20:40:28 volumiopi volumio[1144]: info: CoreStateMachine::pushState May 15 20:40:28 volumiopi volumio[1144]: info: CoreCommandRouter::volumioPushState May 15 20:40:28 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output update for this device May 15 20:40:28 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output May 15 20:40:28 volumiopi volumio[1144]: info: ------------------------------ 40ms May 15 20:40:31 volumiopi systemd[1]: systemd-timedated.service: Deactivated successfully. May 15 20:40:36 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 15 20:40:36 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 15 20:40:36 volumiopi volumio[1144]: info: Discovery: Getting this device information May 15 20:40:36 volumiopi volumio[1144]: info: CoreCommandRouter::volumioGetState May 15 20:40:36 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 15 20:40:41 volumiopi volumio[1144]: info: Removing uri http://opml.radiotime.com/Tune.ashx?id=s139915 from favourites May 15 20:40:41 volumiopi volumio[1144]: info: Saving Cloud item radio-favourites May 15 20:40:41 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: my_volumio , saveCloudItem May 15 20:40:54 volumiopi volumio[1144]: info: Removing uri http://opml.radiotime.com/Tune.ashx?id=s139915 from favourites May 15 20:40:54 volumiopi volumio[1144]: info: Saving Cloud item radio-favourites May 15 20:40:54 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: my_volumio , saveCloudItem May 15 20:41:04 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri May 15 20:41:04 volumiopi volumio[1144]: info: Preload queue cleared May 15 20:41:06 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 15 20:41:06 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 15 20:41:06 volumiopi volumio[1144]: info: Discovery: Getting this device information May 15 20:41:06 volumiopi volumio[1144]: info: CoreCommandRouter::volumioGetState May 15 20:41:06 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 15 20:41:07 volumiopi wpa_supplicant[1043]: wlan0: WPA: Group rekeying completed with b6:fc:7d:01:87:50 [GTK=CCMP] May 15 20:41:07 volumiopi wpa_supplicant[1043]: RRM: Ignoring radio measurement request: Not RRM network May 15 20:41:16 volumiopi wpa_supplicant[1043]: RRM: Ignoring radio measurement request: Not RRM network May 15 20:41:28 volumiopi volumio[1144]: info: Preload queue cleared May 15 20:41:28 volumiopi volumio[1144]: info: CoreCommandRouter::volumioReplaceandPlayItems May 15 20:41:28 volumiopi volumio[1144]: info: CoreStateMachine::ClearQueue May 15 20:41:28 volumiopi volumio[1144]: info: CoreStateMachine::stop May 15 20:41:28 volumiopi volumio[1144]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 20:41:28 volumiopi volumio[1144]: info: CoreStateMachine::stPlaybackTimer May 15 20:41:28 volumiopi volumio[1144]: info: CoreStateMachine::updateTrackBlock May 15 20:41:28 volumiopi volumio[1144]: info: CorePlayQueue::getTrackBlock May 15 20:41:28 volumiopi volumio[1144]: info: CoreStateMachine::pushState May 15 20:41:28 volumiopi volumio[1144]: info: CorePlayQueue::getTrack 0 May 15 20:41:28 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 20:41:28 volumiopi volumio[1144]: info: CoreCommandRouter::volumioPushState May 15 20:41:28 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output update for this device May 15 20:41:28 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output May 15 20:41:28 volumiopi volumio[1144]: info: CoreStateMachine::serviceStop May 15 20:41:28 volumiopi volumio[1144]: info: CorePlayQueue::getTrack 0 May 15 20:41:28 volumiopi volumio[1144]: info: CoreCommandRouter::serviceStop May 15 20:41:28 volumiopi volumio[1144]: info: [1747334488403] ControllerWebradio::stop May 15 20:41:28 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand stop May 15 20:41:28 volumiopi volumio[1144]: info: CorePlayQueue::clearPlayQueue May 15 20:41:28 volumiopi volumio[1144]: info: CorePlayQueue::saveQueue May 15 20:41:28 volumiopi volumio[1144]: info: CoreCommandRouter::volumioPushQueue May 15 20:41:28 volumiopi volumio[1144]: info: CoreStateMachine::addQueueItems May 15 20:41:28 volumiopi volumio[1144]: info: CorePlayQueue::addQueueItems May 15 20:41:28 volumiopi volumio[1144]: info: Preload queue cleared May 15 20:41:28 volumiopi volumio[1144]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s257504 May 15 20:41:28 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri May 15 20:41:28 volumiopi volumio[1144]: info: CoreCommandRouter::volumioPushQueue May 15 20:41:28 volumiopi volumio[1144]: info: CorePlayQueue::saveQueue May 15 20:41:28 volumiopi volumio[1144]: info: CoreStateMachine::updateTrackBlock May 15 20:41:28 volumiopi volumio[1144]: info: CorePlayQueue::getTrackBlock May 15 20:41:28 volumiopi volumio[1144]: info: CoreCommandRouter::volumioPlay May 15 20:41:28 volumiopi volumio[1144]: info: CoreStateMachine::play index 0 May 15 20:41:28 volumiopi volumio[1144]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 20:41:28 volumiopi volumio[1144]: info: CoreStateMachine::stop May 15 20:41:28 volumiopi volumio[1144]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 20:41:28 volumiopi volumio[1144]: info: CoreStateMachine::play index undefined May 15 20:41:28 volumiopi volumio[1144]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 20:41:28 volumiopi volumio[1144]: info: CorePlayQueue::getTrack 0 May 15 20:41:28 volumiopi volumio[1144]: info: CoreStateMachine::startPlaybackTimer May 15 20:41:28 volumiopi volumio[1144]: info: CorePlayQueue::getTrack 0 May 15 20:41:28 volumiopi volumio[1144]: info: CoreCommandRouter::volumioGetVisibleSources May 15 20:41:28 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 15 20:41:28 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 15 20:41:28 volumiopi volumio[1144]: info: [1747334488423] ControllerWebradio::clearAddPlayTrack May 15 20:41:28 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand stop May 15 20:41:28 volumiopi volumio[1144]: info: May 15 20:41:28 volumiopi volumio[1144]: ---------------------------- MPD announces state update: player May 15 20:41:28 volumiopi volumio[1144]: info: sendMpdCommand stop took 42 milliseconds May 15 20:41:28 volumiopi volumio[1144]: info: ControllerMpd::getState May 15 20:41:28 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand status May 15 20:41:28 volumiopi volumio[1144]: info: sendMpdCommand stop took 22 milliseconds May 15 20:41:28 volumiopi volumio[1144]: info: sendMpdCommand status took 1 milliseconds May 15 20:41:28 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand clear May 15 20:41:28 volumiopi volumio[1144]: verbose: ControllerMpd::parseState May 15 20:41:28 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 20:41:28 volumiopi volumio[1144]: info: May 15 20:41:28 volumiopi volumio[1144]: ---------------------------- MPD announces system playlist update May 15 20:41:28 volumiopi volumio[1144]: info: Ignoring MPD Status Update May 15 20:41:28 volumiopi volumio[1144]: info: sendMpdCommand clear took 1 milliseconds May 15 20:41:28 volumiopi volumio[1144]: info: sendMpdCommand playlistinfo took 1 milliseconds May 15 20:41:28 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand load "http://radionetz.de:8000/purefm-hh.mp3" May 15 20:41:28 volumiopi volumio[1144]: verbose: ControllerMpd::parseTrackInfo May 15 20:41:28 volumiopi volumio[1144]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') May 15 20:41:28 volumiopi volumio[1144]: info: ------------------------------ 3ms May 15 20:41:28 volumiopi volumio[1144]: error: updateQueue error: null May 15 20:41:28 volumiopi volumio[1144]: info: ------------------------------ 2ms May 15 20:41:36 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 15 20:41:36 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 15 20:41:36 volumiopi volumio[1144]: info: Discovery: Getting this device information May 15 20:41:36 volumiopi volumio[1144]: info: CoreCommandRouter::volumioGetState May 15 20:41:36 volumiopi volumio[1144]: info: CorePlayQueue::getTrack 0 May 15 20:41:36 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 15 20:41:38 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand add "http://radionetz.de:8000/purefm-hh.mp3" May 15 20:41:38 volumiopi volumio[1144]: info: May 15 20:41:38 volumiopi volumio[1144]: ---------------------------- MPD announces system playlist update May 15 20:41:38 volumiopi volumio[1144]: info: Ignoring MPD Status Update May 15 20:41:38 volumiopi volumio[1144]: info: sendMpdCommand add "http://radionetz.de:8000/purefm-hh.mp3" took 1 milliseconds May 15 20:41:38 volumiopi volumio[1144]: info: CoreStateMachine::setConsumeUpdateService mpd May 15 20:41:38 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand play May 15 20:41:38 volumiopi volumio[1144]: info: ------------------------------ 1ms May 15 20:41:38 volumiopi volumio[1144]: info: sendMpdCommand play took 1 milliseconds May 15 20:41:39 volumiopi volumio[1144]: info: Preload queue cleared May 15 20:41:39 volumiopi volumio[1144]: info: CoreCommandRouter::volumioReplaceandPlayItems May 15 20:41:39 volumiopi volumio[1144]: info: CoreStateMachine::ClearQueue May 15 20:41:39 volumiopi volumio[1144]: info: CoreStateMachine::stop May 15 20:41:39 volumiopi volumio[1144]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 20:41:39 volumiopi volumio[1144]: info: CorePlayQueue::clearPlayQueue May 15 20:41:39 volumiopi volumio[1144]: info: CorePlayQueue::saveQueue May 15 20:41:39 volumiopi volumio[1144]: info: CoreCommandRouter::volumioPushQueue May 15 20:41:39 volumiopi volumio[1144]: info: CoreStateMachine::addQueueItems May 15 20:41:39 volumiopi volumio[1144]: info: CorePlayQueue::addQueueItems May 15 20:41:39 volumiopi volumio[1144]: info: Preload queue cleared May 15 20:41:39 volumiopi volumio[1144]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s307515 May 15 20:41:39 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri May 15 20:41:39 volumiopi volumio[1144]: info: CoreCommandRouter::volumioPushQueue May 15 20:41:39 volumiopi volumio[1144]: info: CorePlayQueue::saveQueue May 15 20:41:39 volumiopi volumio[1144]: info: CoreStateMachine::updateTrackBlock May 15 20:41:39 volumiopi volumio[1144]: info: CorePlayQueue::getTrackBlock May 15 20:41:39 volumiopi volumio[1144]: info: CoreCommandRouter::volumioPlay May 15 20:41:39 volumiopi volumio[1144]: info: CoreStateMachine::play index 0 May 15 20:41:39 volumiopi volumio[1144]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 20:41:39 volumiopi volumio[1144]: info: CoreStateMachine::stop May 15 20:41:39 volumiopi volumio[1144]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 20:41:39 volumiopi volumio[1144]: info: CoreStateMachine::play index undefined May 15 20:41:39 volumiopi volumio[1144]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 20:41:39 volumiopi volumio[1144]: info: CorePlayQueue::getTrack 0 May 15 20:41:39 volumiopi volumio[1144]: info: CoreStateMachine::startPlaybackTimer May 15 20:41:39 volumiopi volumio[1144]: info: CorePlayQueue::getTrack 0 May 15 20:41:39 volumiopi volumio[1144]: info: CoreCommandRouter::volumioGetVisibleSources May 15 20:41:39 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 15 20:41:39 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 15 20:41:39 volumiopi volumio[1144]: info: [1747334499651] ControllerWebradio::clearAddPlayTrack May 15 20:41:39 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand stop May 15 20:41:39 volumiopi volumio[1144]: info: May 15 20:41:39 volumiopi volumio[1144]: ---------------------------- MPD announces state update: player May 15 20:41:39 volumiopi volumio[1144]: info: sendMpdCommand stop took 4 milliseconds May 15 20:41:39 volumiopi volumio[1144]: info: ControllerMpd::getState May 15 20:41:39 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand status May 15 20:41:39 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand clear May 15 20:41:39 volumiopi volumio[1144]: info: May 15 20:41:39 volumiopi volumio[1144]: ---------------------------- MPD announces system playlist update May 15 20:41:39 volumiopi volumio[1144]: info: Ignoring MPD Status Update May 15 20:41:39 volumiopi volumio[1144]: info: sendMpdCommand status took 2 milliseconds May 15 20:41:39 volumiopi volumio[1144]: info: sendMpdCommand clear took 1 milliseconds May 15 20:41:39 volumiopi volumio[1144]: verbose: ControllerMpd::parseState May 15 20:41:39 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 20:41:39 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand load "https://wdr-cosmo-chillout.icecastssl.wdr.de/wdr/cosmo/chillout/mp3/128/stream.mp3?aggregator=tunein" May 15 20:41:39 volumiopi volumio[1144]: error: updateQueue error: null May 15 20:41:39 volumiopi volumio[1144]: info: ------------------------------ 4ms May 15 20:41:39 volumiopi volumio[1144]: info: sendMpdCommand playlistinfo took 2 milliseconds May 15 20:41:39 volumiopi volumio[1144]: verbose: ControllerMpd::parseTrackInfo May 15 20:41:39 volumiopi volumio[1144]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') May 15 20:41:39 volumiopi volumio[1144]: info: ------------------------------ 6ms May 15 20:41:40 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand add "https://wdr-cosmo-chillout.icecastssl.wdr.de/wdr/cosmo/chillout/mp3/128/stream.mp3?aggregator=tunein" May 15 20:41:40 volumiopi volumio[1144]: info: sendMpdCommand add "https://wdr-cosmo-chillout.icecastssl.wdr.de/wdr/cosmo/chillout/mp3/128/stream.mp3?aggregator=tunein" took 1 milliseconds May 15 20:41:40 volumiopi volumio[1144]: info: CoreStateMachine::setConsumeUpdateService mpd May 15 20:41:40 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand play May 15 20:41:40 volumiopi volumio[1144]: info: May 15 20:41:40 volumiopi volumio[1144]: ---------------------------- MPD announces system playlist update May 15 20:41:40 volumiopi volumio[1144]: info: Ignoring MPD Status Update May 15 20:41:40 volumiopi volumio[1144]: info: sendMpdCommand play took 2 milliseconds May 15 20:41:40 volumiopi volumio[1144]: info: ------------------------------ 2ms May 15 20:41:41 volumiopi volumio[1144]: info: May 15 20:41:41 volumiopi volumio[1144]: ---------------------------- MPD announces state update: player May 15 20:41:41 volumiopi volumio[1144]: info: ControllerMpd::getState May 15 20:41:41 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand status May 15 20:41:41 volumiopi volumio[1144]: info: May 15 20:41:41 volumiopi volumio[1144]: ---------------------------- MPD announces state update: player May 15 20:41:41 volumiopi volumio[1144]: info: sendMpdCommand status took 9 milliseconds May 15 20:41:41 volumiopi volumio[1144]: info: ControllerMpd::getState May 15 20:41:41 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand status May 15 20:41:41 volumiopi volumio[1144]: verbose: ControllerMpd::parseState May 15 20:41:41 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 20:41:41 volumiopi volumio[1144]: info: sendMpdCommand status took 1 milliseconds May 15 20:41:41 volumiopi volumio[1144]: info: sendMpdCommand playlistinfo took 1 milliseconds May 15 20:41:41 volumiopi volumio[1144]: verbose: ControllerMpd::parseState May 15 20:41:41 volumiopi volumio[1144]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 20:41:41 volumiopi volumio[1144]: verbose: ControllerMpd::parseTrackInfo May 15 20:41:41 volumiopi volumio[1144]: info: ControllerMpd::pushState May 15 20:41:41 volumiopi volumio[1144]: info: CoreCommandRouter::servicePushState May 15 20:41:41 volumiopi volumio[1144]: info: CorePlayQueue::getTrack 0 May 15 20:41:41 volumiopi volumio[1144]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"stream.mp3?aggregator=tunein","artist":null,"album":null,"uri":"https://wdr-cosmo-chillout.icecastssl.wdr.de/wdr/cosmo/chillout/mp3/128/stream.mp3?aggregator=tunein","trackType":""} May 15 20:41:41 volumiopi volumio[1144]: verbose: CURRENT POSITION 0 May 15 20:41:41 volumiopi volumio[1144]: info: CoreStateMachine::syncState stateService play May 15 20:41:41 volumiopi volumio[1144]: info: CoreStateMachine::syncState currentStatus stop May 15 20:41:41 volumiopi volumio[1144]: info: ------------------------------ 14ms May 15 20:41:41 volumiopi volumio[1144]: info: sendMpdCommand playlistinfo took 2 milliseconds May 15 20:41:41 volumiopi volumio[1144]: verbose: ControllerMpd::parseTrackInfo May 15 20:41:41 volumiopi volumio[1144]: info: ControllerMpd::pushState May 15 20:41:41 volumiopi volumio[1144]: info: CoreCommandRouter::servicePushState May 15 20:41:41 volumiopi volumio[1144]: info: CorePlayQueue::getTrack 0 May 15 20:41:41 volumiopi volumio[1144]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"stream.mp3?aggregator=tunein","artist":null,"album":null,"uri":"https://wdr-cosmo-chillout.icecastssl.wdr.de/wdr/cosmo/chillout/mp3/128/stream.mp3?aggregator=tunein","trackType":""} May 15 20:41:41 volumiopi volumio[1144]: verbose: CURRENT POSITION 0 May 15 20:41:41 volumiopi volumio[1144]: info: CoreStateMachine::syncState stateService play May 15 20:41:41 volumiopi volumio[1144]: info: CoreStateMachine::syncState currentStatus play May 15 20:41:41 volumiopi volumio[1144]: info: Received an update from plugin. extracting info from payload May 15 20:41:41 volumiopi volumio[1144]: info: CoreStateMachine::pushState May 15 20:41:41 volumiopi volumio[1144]: info: CorePlayQueue::getTrack 0 May 15 20:41:41 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 20:41:41 volumiopi volumio[1144]: info: CoreCommandRouter::volumioPushState May 15 20:41:41 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output update for this device May 15 20:41:41 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output May 15 20:41:41 volumiopi volumio[1144]: info: CoreStateMachine::pushState May 15 20:41:41 volumiopi volumio[1144]: info: CoreCommandRouter::volumioPushState May 15 20:41:41 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output update for this device May 15 20:41:41 volumiopi volumio[1144]: info: MRS: Pushing multiroomSync output May 15 20:41:41 volumiopi volumio[1144]: info: ------------------------------ 32ms May 15 20:41:44 volumiopi volumio[1144]: info: Removing uri http://opml.radiotime.com/Tune.ashx?id=s257504 from favourites May 15 20:41:44 volumiopi volumio[1144]: info: Saving Cloud item radio-favourites May 15 20:41:44 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: my_volumio , saveCloudItem May 15 20:41:55 volumiopi volumio[1144]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri May 15 20:41:55 volumiopi systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... May 15 20:41:55 volumiopi dbus-daemon[689]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.64' (uid=0 pid=4065 comm="timedatectl show --property=NTPSynchronized --valu") May 15 20:41:55 volumiopi systemd[1]: Starting systemd-timedated.service - Time & Date Service... May 15 20:41:55 volumiopi dbus-daemon[689]: [system] Successfully activated service 'org.freedesktop.timedate1' May 15 20:41:55 volumiopi systemd[1]: Started systemd-timedated.service - Time & Date Service. May 15 20:41:55 volumiopi setdatetime-helper.sh[4064]: Time is not synchronized. Attempting to sync... May 15 20:41:55 volumiopi sudo[4073]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Thu, 15 May 2025 18:41:56 GMT#015' May 15 20:41:55 volumiopi sudo[4073]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 15 20:41:56 volumiopi setdatetime-helper.sh[4074]: Thu May 15 20:41:56 CEST 2025 May 15 20:41:56 volumiopi sudo[4073]: pam_unix(sudo:session): session closed for user root May 15 20:41:56 volumiopi setdatetime-helper.sh[4064]: Time synchronized successfully. May 15 20:41:56 volumiopi systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. May 15 20:41:56 volumiopi systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. May 15 20:41:57 volumiopi volumio[1144]: info: READ May 15 20:41:57 volumiopi volumio[1144]: Use XMLElement.setAttribute instead May 15 20:41:57 volumiopi volumio[1144]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 15 20:41:57 volumiopi volumio[1144]: TypeError: children[i].attr(...).value is not a function May 15 20:41:57 volumiopi volumio[1144]: at /volumio/app/plugins/music_service/webradio/index.js:286:47 May 15 20:41:57 volumiopi volumio[1144]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) May 15 20:41:57 volumiopi volumio[1144]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 15 20:41:58 volumiopi sudo[4089]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-05-15 20:40' May 15 20:41:58 volumiopi sudo[4089]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="74e551e797a3a333b0b20739125f2f8b0b974aba" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed May 14 16:06:36 UTC 2025" VOLUMIO_VERSION="0.066" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="72f9e088cb36b840954a7bc22b48bde7"