Jun 09 10:42:18 volumio systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Jun 09 10:42:18 volumio dbus-daemon[623]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.59' (uid=0 pid=4528 comm="timedatectl show --property=NTPSynchronized --valu") Jun 09 10:42:18 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service... Jun 09 10:42:18 volumio dbus-daemon[623]: [system] Successfully activated service 'org.freedesktop.timedate1' Jun 09 10:42:18 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service. Jun 09 10:42:18 volumio setdatetime-helper.sh[4527]: Time is not synchronized. Attempting to sync... Jun 09 10:42:19 volumio sudo[4536]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Mon, 09 Jun 2025 01:42:19 GMT#015' Jun 09 10:42:19 volumio sudo[4536]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 09 10:42:19 volumio setdatetime-helper.sh[4537]: Mon Jun 9 10:42:19 KST 2025 Jun 09 10:42:19 volumio systemd-journald[375]: Time jumped backwards, rotating. Jun 09 10:42:19 volumio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Jun 09 10:42:19 volumio setdatetime-helper.sh[4527]: Time synchronized successfully. Jun 09 10:42:19 volumio sudo[4536]: pam_unix(sudo:session): session closed for user root Jun 09 10:42:19 volumio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Jun 09 10:42:31 volumio volumio[1139]: verbose: New Socket.io Connection to 172.30.1.48 from 172.30.1.97 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_5 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/18.5 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 5 Jun 09 10:42:31 volumio volumio[1139]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 09 10:42:31 volumio volumio[1139]: info: CoreCommandRouter::volumioGetVisibleSources Jun 09 10:42:31 volumio volumio[1139]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 09 10:42:31 volumio volumio[1139]: info: CoreCommandRouter::volumioGetState Jun 09 10:42:31 volumio volumio[1139]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 09 10:42:31 volumio volumio[1139]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 09 10:42:31 volumio volumio[1139]: info: Received Get System Info Jun 09 10:42:31 volumio volumio[1139]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 09 10:42:31 volumio volumio[1139]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 09 10:42:31 volumio volumio[1139]: info: Discovery: Getting this device information Jun 09 10:42:31 volumio volumio[1139]: info: CoreCommandRouter::volumioGetState Jun 09 10:42:31 volumio volumio[1139]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 09 10:42:31 volumio volumio[1139]: info: CoreCommandRouter::volumioGetState Jun 09 10:42:31 volumio volumio[1139]: info: Listing playlists Jun 09 10:42:31 volumio volumio[1139]: info: CoreCommandRouter::volumioGetQueue Jun 09 10:42:31 volumio volumio[1139]: info: CoreStateMachine::getQueue Jun 09 10:42:31 volumio volumio[1139]: info: CorePlayQueue::getQueue Jun 09 10:42:31 volumio volumio[1139]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jun 09 10:42:48 volumio systemd[1]: systemd-timedated.service: Deactivated successfully. Jun 09 10:42:54 volumio volumio[1139]: info: CoreCommandRouter::executeOnPlugin: webradio , addMyWebRadio Jun 09 10:42:54 volumio volumio[1139]: info: {"name":"Radio Suisse Classique","uri":"https://stream.srg-ssr.ch/rsc_fr/aacp_96.m3u"} Jun 09 10:42:54 volumio volumio[1139]: info: Saving local item my-web-radio Jun 09 10:42:55 volumio volumio[1139]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Jun 09 10:42:55 volumio volumio[1139]: info: Preload queue cleared Jun 09 10:42:57 volumio volumio[1139]: info: Preload queue cleared Jun 09 10:42:57 volumio volumio[1139]: info: CoreCommandRouter::volumioReplaceandPlayItems Jun 09 10:42:57 volumio volumio[1139]: info: CoreStateMachine::ClearQueue Jun 09 10:42:57 volumio volumio[1139]: info: CoreStateMachine::stop Jun 09 10:42:57 volumio volumio[1139]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 09 10:42:57 volumio volumio[1139]: info: CoreStateMachine::stPlaybackTimer Jun 09 10:42:57 volumio volumio[1139]: info: CoreStateMachine::updateTrackBlock Jun 09 10:42:57 volumio volumio[1139]: info: CorePlayQueue::getTrackBlock Jun 09 10:42:57 volumio volumio[1139]: info: CoreStateMachine::pushState Jun 09 10:42:57 volumio volumio[1139]: info: CorePlayQueue::getTrack 0 Jun 09 10:42:57 volumio volumio[1139]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 09 10:42:57 volumio volumio[1139]: info: CoreCommandRouter::volumioPushState Jun 09 10:42:57 volumio volumio[1139]: info: CoreStateMachine::serviceStop Jun 09 10:42:57 volumio volumio[1139]: info: CorePlayQueue::getTrack 0 Jun 09 10:42:57 volumio volumio[1139]: info: CoreCommandRouter::serviceStop Jun 09 10:42:57 volumio volumio[1139]: info: [1749433377274] ControllerWebradio::stop Jun 09 10:42:57 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand stop Jun 09 10:42:57 volumio volumio[1139]: info: CorePlayQueue::clearPlayQueue Jun 09 10:42:57 volumio volumio[1139]: info: CorePlayQueue::saveQueue Jun 09 10:42:57 volumio volumio[1139]: info: CoreCommandRouter::volumioPushQueue Jun 09 10:42:57 volumio volumio[1139]: info: CoreStateMachine::addQueueItems Jun 09 10:42:57 volumio volumio[1139]: info: CorePlayQueue::addQueueItems Jun 09 10:42:57 volumio volumio[1139]: info: Preload queue cleared Jun 09 10:42:57 volumio volumio[1139]: info: Adding Item to queue: https://stream.srg-ssr.ch/rsc_fr/aacp_96.m3u Jun 09 10:42:57 volumio volumio[1139]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Jun 09 10:42:57 volumio volumio[1139]: info: CoreCommandRouter::volumioPushQueue Jun 09 10:42:57 volumio volumio[1139]: info: CorePlayQueue::saveQueue Jun 09 10:42:57 volumio volumio[1139]: info: CoreStateMachine::updateTrackBlock Jun 09 10:42:57 volumio volumio[1139]: info: CorePlayQueue::getTrackBlock Jun 09 10:42:57 volumio volumio[1139]: info: CoreCommandRouter::volumioPlay Jun 09 10:42:57 volumio volumio[1139]: info: CoreStateMachine::play index 0 Jun 09 10:42:57 volumio volumio[1139]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 09 10:42:57 volumio volumio[1139]: info: CoreStateMachine::stop Jun 09 10:42:57 volumio volumio[1139]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 09 10:42:57 volumio volumio[1139]: info: CoreStateMachine::play index undefined Jun 09 10:42:57 volumio volumio[1139]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 09 10:42:57 volumio volumio[1139]: info: CorePlayQueue::getTrack 0 Jun 09 10:42:57 volumio volumio[1139]: info: CoreStateMachine::startPlaybackTimer Jun 09 10:42:57 volumio volumio[1139]: info: CorePlayQueue::getTrack 0 Jun 09 10:42:57 volumio volumio[1139]: info: [1749433377315] ControllerWebradio::clearAddPlayTrack Jun 09 10:42:57 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand stop Jun 09 10:42:57 volumio volumio[1139]: info: Jun 09 10:42:57 volumio volumio[1139]: ---------------------------- MPD announces state update: player Jun 09 10:42:57 volumio volumio[1139]: info: sendMpdCommand stop took 64 milliseconds Jun 09 10:42:57 volumio volumio[1139]: info: ControllerMpd::getState Jun 09 10:42:57 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand status Jun 09 10:42:57 volumio volumio[1139]: info: sendMpdCommand stop took 27 milliseconds Jun 09 10:42:57 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand clear Jun 09 10:42:57 volumio volumio[1139]: info: Jun 09 10:42:57 volumio volumio[1139]: ---------------------------- MPD announces state update: player Jun 09 10:42:57 volumio volumio[1139]: info: ControllerMpd::getState Jun 09 10:42:57 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand status Jun 09 10:42:57 volumio volumio[1139]: info: Jun 09 10:42:57 volumio volumio[1139]: ---------------------------- MPD announces system playlist update Jun 09 10:42:57 volumio volumio[1139]: info: Ignoring MPD Status Update Jun 09 10:42:57 volumio volumio[1139]: info: sendMpdCommand status took 5 milliseconds Jun 09 10:42:57 volumio volumio[1139]: info: sendMpdCommand clear took 4 milliseconds Jun 09 10:42:57 volumio volumio[1139]: info: sendMpdCommand status took 3 milliseconds Jun 09 10:42:57 volumio volumio[1139]: verbose: ControllerMpd::parseState Jun 09 10:42:57 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 09 10:42:57 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand load "https://stream.srg-ssr.ch/rsc_fr/aacp_96.m3u" Jun 09 10:42:57 volumio volumio[1139]: verbose: ControllerMpd::parseState Jun 09 10:42:57 volumio volumio[1139]: info: ControllerMpd::pushState Jun 09 10:42:57 volumio volumio[1139]: info: CoreCommandRouter::servicePushState Jun 09 10:42:57 volumio volumio[1139]: info: CoreStateMachine::pushState Jun 09 10:42:57 volumio volumio[1139]: info: CorePlayQueue::getTrack 0 Jun 09 10:42:57 volumio volumio[1139]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 09 10:42:57 volumio volumio[1139]: info: CoreCommandRouter::volumioPushState Jun 09 10:42:57 volumio volumio[1139]: info: CorePlayQueue::getTrack 0 Jun 09 10:42:57 volumio volumio[1139]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Jun 09 10:42:57 volumio volumio[1139]: info: ------------------------------ 23ms Jun 09 10:42:57 volumio volumio[1139]: info: Jun 09 10:42:57 volumio volumio[1139]: ---------------------------- MPD announces system playlist update Jun 09 10:42:57 volumio volumio[1139]: info: Ignoring MPD Status Update Jun 09 10:42:57 volumio volumio[1139]: error: updateQueue error: null Jun 09 10:42:57 volumio volumio[1139]: info: ------------------------------ 24ms Jun 09 10:42:57 volumio volumio[1139]: info: sendMpdCommand playlistinfo took 21 milliseconds Jun 09 10:42:57 volumio volumio[1139]: verbose: ControllerMpd::parseTrackInfo Jun 09 10:42:57 volumio volumio[1139]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Jun 09 10:42:57 volumio volumio[1139]: info: ------------------------------ 32ms Jun 09 10:42:58 volumio volumio[1139]: info: sendMpdCommand load "https://stream.srg-ssr.ch/rsc_fr/aacp_96.m3u" took 1614 milliseconds Jun 09 10:42:58 volumio volumio[1139]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 09 10:42:58 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand play Jun 09 10:42:58 volumio volumio[1139]: info: Jun 09 10:42:58 volumio volumio[1139]: ---------------------------- MPD announces system playlist update Jun 09 10:42:58 volumio volumio[1139]: info: Ignoring MPD Status Update Jun 09 10:42:58 volumio volumio[1139]: info: ------------------------------ 1598ms Jun 09 10:42:58 volumio volumio[1139]: info: Jun 09 10:42:58 volumio volumio[1139]: ---------------------------- MPD announces system playlist update Jun 09 10:42:58 volumio volumio[1139]: info: Ignoring MPD Status Update Jun 09 10:42:58 volumio volumio[1139]: info: sendMpdCommand play took 5 milliseconds Jun 09 10:42:58 volumio volumio[1139]: info: ------------------------------ 4ms Jun 09 10:42:58 volumio volumio[1139]: info: ------------------------------ 3ms Jun 09 10:43:01 volumio volumio[1139]: info: Jun 09 10:43:01 volumio volumio[1139]: ---------------------------- MPD announces state update: player Jun 09 10:43:01 volumio volumio[1139]: info: ControllerMpd::getState Jun 09 10:43:01 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand status Jun 09 10:43:01 volumio volumio[1139]: info: Jun 09 10:43:01 volumio volumio[1139]: ---------------------------- MPD announces state update: player Jun 09 10:43:01 volumio volumio[1139]: info: Jun 09 10:43:01 volumio volumio[1139]: ---------------------------- MPD announces state update: player Jun 09 10:43:01 volumio volumio[1139]: info: ControllerMpd::getState Jun 09 10:43:01 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand status Jun 09 10:43:01 volumio volumio[1139]: info: sendMpdCommand status took 4 milliseconds Jun 09 10:43:01 volumio volumio[1139]: info: ControllerMpd::getState Jun 09 10:43:01 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand status Jun 09 10:43:01 volumio volumio[1139]: verbose: ControllerMpd::parseState Jun 09 10:43:01 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 09 10:43:01 volumio volumio[1139]: info: Jun 09 10:43:01 volumio volumio[1139]: ---------------------------- MPD announces state update: player Jun 09 10:43:01 volumio volumio[1139]: info: ControllerMpd::getState Jun 09 10:43:01 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand status Jun 09 10:43:01 volumio volumio[1139]: info: sendMpdCommand status took 6 milliseconds Jun 09 10:43:01 volumio volumio[1139]: info: sendMpdCommand status took 6 milliseconds Jun 09 10:43:01 volumio volumio[1139]: info: sendMpdCommand playlistinfo took 6 milliseconds Jun 09 10:43:01 volumio volumio[1139]: verbose: ControllerMpd::parseState Jun 09 10:43:01 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 09 10:43:01 volumio volumio[1139]: verbose: ControllerMpd::parseState Jun 09 10:43:01 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 09 10:43:01 volumio volumio[1139]: verbose: ControllerMpd::parseTrackInfo Jun 09 10:43:01 volumio volumio[1139]: info: ControllerMpd::pushState Jun 09 10:43:01 volumio volumio[1139]: info: CoreCommandRouter::servicePushState Jun 09 10:43:01 volumio volumio[1139]: info: CorePlayQueue::getTrack 0 Jun 09 10:43:01 volumio volumio[1139]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"96","artist":null,"album":null,"uri":"http://stream.srg-ssr.ch/srgssr/rsc_fr/aac/96","trackType":""} Jun 09 10:43:01 volumio volumio[1139]: verbose: CURRENT POSITION 0 Jun 09 10:43:01 volumio volumio[1139]: info: CoreStateMachine::syncState stateService play Jun 09 10:43:01 volumio volumio[1139]: info: CoreStateMachine::syncState currentStatus stop Jun 09 10:43:01 volumio volumio[1139]: info: ------------------------------ 20ms Jun 09 10:43:01 volumio volumio[1139]: info: sendMpdCommand status took 11 milliseconds Jun 09 10:43:01 volumio volumio[1139]: info: sendMpdCommand playlistinfo took 8 milliseconds Jun 09 10:43:01 volumio volumio[1139]: info: sendMpdCommand playlistinfo took 7 milliseconds Jun 09 10:43:01 volumio volumio[1139]: verbose: ControllerMpd::parseState Jun 09 10:43:01 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 09 10:43:01 volumio volumio[1139]: verbose: ControllerMpd::parseTrackInfo Jun 09 10:43:01 volumio volumio[1139]: verbose: ControllerMpd::parseTrackInfo Jun 09 10:43:01 volumio volumio[1139]: info: ControllerMpd::pushState Jun 09 10:43:01 volumio volumio[1139]: info: CoreCommandRouter::servicePushState Jun 09 10:43:01 volumio volumio[1139]: info: CorePlayQueue::getTrack 0 Jun 09 10:43:01 volumio volumio[1139]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"96","artist":null,"album":null,"uri":"http://stream.srg-ssr.ch/srgssr/rsc_fr/aac/96","trackType":""} Jun 09 10:43:01 volumio volumio[1139]: verbose: CURRENT POSITION 0 Jun 09 10:43:01 volumio volumio[1139]: info: CoreStateMachine::syncState stateService play Jun 09 10:43:01 volumio volumio[1139]: info: CoreStateMachine::syncState currentStatus play Jun 09 10:43:01 volumio volumio[1139]: info: Received an update from plugin. extracting info from payload Jun 09 10:43:01 volumio volumio[1139]: info: CoreStateMachine::pushState Jun 09 10:43:01 volumio volumio[1139]: info: CorePlayQueue::getTrack 0 Jun 09 10:43:01 volumio volumio[1139]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 09 10:43:01 volumio volumio[1139]: info: CoreCommandRouter::volumioPushState Jun 09 10:43:01 volumio volumio[1139]: info: CoreStateMachine::pushState Jun 09 10:43:01 volumio volumio[1139]: info: CoreCommandRouter::volumioPushState Jun 09 10:43:01 volumio volumio[1139]: info: ControllerMpd::pushState Jun 09 10:43:01 volumio volumio[1139]: info: CoreCommandRouter::servicePushState Jun 09 10:43:01 volumio volumio[1139]: info: CorePlayQueue::getTrack 0 Jun 09 10:43:01 volumio volumio[1139]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"96","artist":null,"album":null,"uri":"http://stream.srg-ssr.ch/srgssr/rsc_fr/aac/96","trackType":""} Jun 09 10:43:01 volumio volumio[1139]: verbose: CURRENT POSITION 0 Jun 09 10:43:01 volumio volumio[1139]: info: CoreStateMachine::syncState stateService play Jun 09 10:43:01 volumio volumio[1139]: info: CoreStateMachine::syncState currentStatus play Jun 09 10:43:01 volumio volumio[1139]: info: Received an update from plugin. extracting info from payload Jun 09 10:43:01 volumio volumio[1139]: info: CoreStateMachine::pushState Jun 09 10:43:01 volumio volumio[1139]: info: CorePlayQueue::getTrack 0 Jun 09 10:43:01 volumio volumio[1139]: info: CoreCommandRouter::volumioPushState Jun 09 10:43:01 volumio volumio[1139]: info: CoreStateMachine::pushState Jun 09 10:43:01 volumio volumio[1139]: info: CoreCommandRouter::volumioPushState Jun 09 10:43:01 volumio volumio[1139]: info: ------------------------------ 84ms Jun 09 10:43:01 volumio volumio[1139]: info: ------------------------------ 83ms Jun 09 10:43:01 volumio volumio[1139]: info: Jun 09 10:43:01 volumio volumio[1139]: ---------------------------- MPD announces system playlist update Jun 09 10:43:01 volumio volumio[1139]: info: Ignoring MPD Status Update Jun 09 10:43:01 volumio volumio[1139]: info: Jun 09 10:43:01 volumio volumio[1139]: ---------------------------- MPD announces state update: player Jun 09 10:43:01 volumio volumio[1139]: info: ControllerMpd::getState Jun 09 10:43:01 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand status Jun 09 10:43:01 volumio volumio[1139]: info: sendMpdCommand playlistinfo took 66 milliseconds Jun 09 10:43:01 volumio volumio[1139]: verbose: ControllerMpd::parseTrackInfo Jun 09 10:43:01 volumio volumio[1139]: info: ControllerMpd::pushState Jun 09 10:43:01 volumio volumio[1139]: info: CoreCommandRouter::servicePushState Jun 09 10:43:01 volumio volumio[1139]: info: CorePlayQueue::getTrack 0 Jun 09 10:43:01 volumio volumio[1139]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Radio Suisse Classique - www.radiosuisseclassique.ch","artist":"Swiss Classic F","album":null,"uri":"http://stream.srg-ssr.ch/srgssr/rsc_fr/aac/96","trackType":""} Jun 09 10:43:01 volumio volumio[1139]: verbose: CURRENT POSITION 0 Jun 09 10:43:01 volumio volumio[1139]: info: CoreStateMachine::syncState stateService play Jun 09 10:43:01 volumio volumio[1139]: info: CoreStateMachine::syncState currentStatus play Jun 09 10:43:01 volumio volumio[1139]: info: Received an update from plugin. extracting info from payload Jun 09 10:43:01 volumio volumio[1139]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Jun 09 10:43:01 volumio volumio[1139]: info: CoreStateMachine::pushState Jun 09 10:43:01 volumio volumio[1139]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 09 10:43:01 volumio volumio[1139]: info: CoreCommandRouter::volumioPushState Jun 09 10:43:01 volumio volumio[1139]: info: CoreStateMachine::pushState Jun 09 10:43:01 volumio volumio[1139]: info: CoreCommandRouter::volumioPushState Jun 09 10:43:01 volumio volumio[1139]: info: ------------------------------ 105ms Jun 09 10:43:01 volumio volumio[1139]: info: Jun 09 10:43:01 volumio volumio[1139]: ---------------------------- MPD announces system playlist update Jun 09 10:43:01 volumio volumio[1139]: info: Ignoring MPD Status Update Jun 09 10:43:01 volumio volumio[1139]: info: Jun 09 10:43:01 volumio volumio[1139]: ---------------------------- MPD announces state update: player Jun 09 10:43:01 volumio volumio[1139]: info: ControllerMpd::getState Jun 09 10:43:01 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand status Jun 09 10:43:01 volumio volumio[1139]: info: ------------------------------ 47ms Jun 09 10:43:01 volumio volumio[1139]: info: sendMpdCommand status took 46 milliseconds Jun 09 10:43:01 volumio volumio[1139]: info: ------------------------------ 21ms Jun 09 10:43:01 volumio volumio[1139]: info: sendMpdCommand status took 21 milliseconds Jun 09 10:43:01 volumio volumio[1139]: verbose: ControllerMpd::parseState Jun 09 10:43:01 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 09 10:43:01 volumio volumio[1139]: verbose: ControllerMpd::parseState Jun 09 10:43:01 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 09 10:43:01 volumio volumio[1139]: info: sendMpdCommand playlistinfo took 4 milliseconds Jun 09 10:43:01 volumio volumio[1139]: info: sendMpdCommand playlistinfo took 4 milliseconds Jun 09 10:43:01 volumio volumio[1139]: verbose: ControllerMpd::parseTrackInfo Jun 09 10:43:01 volumio volumio[1139]: verbose: ControllerMpd::parseTrackInfo Jun 09 10:43:01 volumio volumio[1139]: info: ControllerMpd::pushState Jun 09 10:43:01 volumio volumio[1139]: info: CoreCommandRouter::servicePushState Jun 09 10:43:01 volumio volumio[1139]: info: CorePlayQueue::getTrack 0 Jun 09 10:43:01 volumio volumio[1139]: verbose: STATE SERVICE {"status":"play","position":0,"seek":989,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"96 Kbps","isStreaming":false,"title":"Radio Suisse Classique - www.radiosuisseclassique.ch","artist":"Swiss Classic F","album":null,"uri":"http://stream.srg-ssr.ch/srgssr/rsc_fr/aac/96","trackType":""} Jun 09 10:43:01 volumio volumio[1139]: verbose: CURRENT POSITION 0 Jun 09 10:43:01 volumio volumio[1139]: info: CoreStateMachine::syncState stateService play Jun 09 10:43:01 volumio volumio[1139]: info: CoreStateMachine::syncState currentStatus play Jun 09 10:43:01 volumio volumio[1139]: info: Received an update from plugin. extracting info from payload Jun 09 10:43:01 volumio volumio[1139]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Jun 09 10:43:01 volumio volumio[1139]: info: CoreStateMachine::pushState Jun 09 10:43:01 volumio volumio[1139]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 09 10:43:01 volumio volumio[1139]: info: CoreCommandRouter::volumioPushState Jun 09 10:43:01 volumio volumio[1139]: info: CoreStateMachine::pushState Jun 09 10:43:01 volumio volumio[1139]: info: CoreCommandRouter::volumioPushState Jun 09 10:43:01 volumio volumio[1139]: info: ControllerMpd::pushState Jun 09 10:43:01 volumio volumio[1139]: info: CoreCommandRouter::servicePushState Jun 09 10:43:01 volumio volumio[1139]: info: CorePlayQueue::getTrack 0 Jun 09 10:43:01 volumio volumio[1139]: verbose: STATE SERVICE {"status":"play","position":0,"seek":989,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"96 Kbps","isStreaming":false,"title":"Radio Suisse Classique - www.radiosuisseclassique.ch","artist":"Swiss Classic F","album":null,"uri":"http://stream.srg-ssr.ch/srgssr/rsc_fr/aac/96","trackType":""} Jun 09 10:43:01 volumio volumio[1139]: verbose: CURRENT POSITION 0 Jun 09 10:43:01 volumio volumio[1139]: info: CoreStateMachine::syncState stateService play Jun 09 10:43:01 volumio volumio[1139]: info: CoreStateMachine::syncState currentStatus play Jun 09 10:43:01 volumio volumio[1139]: info: Received an update from plugin. extracting info from payload Jun 09 10:43:01 volumio volumio[1139]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Jun 09 10:43:01 volumio volumio[1139]: info: CoreStateMachine::pushState Jun 09 10:43:01 volumio volumio[1139]: info: CoreCommandRouter::volumioPushState Jun 09 10:43:01 volumio volumio[1139]: info: CoreStateMachine::pushState Jun 09 10:43:01 volumio volumio[1139]: info: CoreCommandRouter::volumioPushState Jun 09 10:43:01 volumio volumio[1139]: info: ------------------------------ 102ms Jun 09 10:43:01 volumio volumio[1139]: info: ------------------------------ 76ms Jun 09 10:43:27 volumio volumio[1139]: info: Jun 09 10:43:27 volumio volumio[1139]: ---------------------------- MPD announces system playlist update Jun 09 10:43:27 volumio volumio[1139]: info: Ignoring MPD Status Update Jun 09 10:43:27 volumio volumio[1139]: info: Jun 09 10:43:27 volumio volumio[1139]: ---------------------------- MPD announces state update: player Jun 09 10:43:27 volumio volumio[1139]: info: ControllerMpd::getState Jun 09 10:43:27 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand status Jun 09 10:43:27 volumio volumio[1139]: info: Jun 09 10:43:27 volumio volumio[1139]: ---------------------------- MPD announces system playlist update Jun 09 10:43:27 volumio volumio[1139]: info: Ignoring MPD Status Update Jun 09 10:43:27 volumio volumio[1139]: info: Jun 09 10:43:27 volumio volumio[1139]: ---------------------------- MPD announces state update: player Jun 09 10:43:27 volumio volumio[1139]: info: ControllerMpd::getState Jun 09 10:43:27 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand status Jun 09 10:43:27 volumio volumio[1139]: info: ------------------------------ 7ms Jun 09 10:43:27 volumio volumio[1139]: info: sendMpdCommand status took 5 milliseconds Jun 09 10:43:27 volumio volumio[1139]: info: ------------------------------ 5ms Jun 09 10:43:27 volumio volumio[1139]: info: sendMpdCommand status took 4 milliseconds Jun 09 10:43:27 volumio volumio[1139]: verbose: ControllerMpd::parseState Jun 09 10:43:27 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 09 10:43:27 volumio volumio[1139]: verbose: ControllerMpd::parseState Jun 09 10:43:27 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 09 10:43:27 volumio volumio[1139]: info: sendMpdCommand playlistinfo took 3 milliseconds Jun 09 10:43:27 volumio volumio[1139]: info: sendMpdCommand playlistinfo took 4 milliseconds Jun 09 10:43:27 volumio volumio[1139]: verbose: ControllerMpd::parseTrackInfo Jun 09 10:43:27 volumio volumio[1139]: verbose: ControllerMpd::parseTrackInfo Jun 09 10:43:27 volumio volumio[1139]: info: ControllerMpd::pushState Jun 09 10:43:27 volumio volumio[1139]: info: CoreCommandRouter::servicePushState Jun 09 10:43:27 volumio volumio[1139]: info: CorePlayQueue::getTrack 0 Jun 09 10:43:27 volumio volumio[1139]: verbose: STATE SERVICE {"status":"play","position":0,"seek":27606,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"96 Kbps","isStreaming":false,"title":"Pjotr Iljitsch Tchaikovsky - Méditation de Souvenir d'un lieu cher ","artist":"Swiss Classic F","album":null,"uri":"http://stream.srg-ssr.ch/srgssr/rsc_fr/aac/96","trackType":""} Jun 09 10:43:27 volumio volumio[1139]: verbose: CURRENT POSITION 0 Jun 09 10:43:27 volumio volumio[1139]: info: CoreStateMachine::syncState stateService play Jun 09 10:43:27 volumio volumio[1139]: info: CoreStateMachine::syncState currentStatus play Jun 09 10:43:27 volumio volumio[1139]: info: Received an update from plugin. extracting info from payload Jun 09 10:43:27 volumio volumio[1139]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Jun 09 10:43:27 volumio volumio[1139]: info: CoreStateMachine::pushState Jun 09 10:43:27 volumio volumio[1139]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 09 10:43:27 volumio volumio[1139]: info: CoreCommandRouter::volumioPushState Jun 09 10:43:27 volumio volumio[1139]: info: CoreStateMachine::pushState Jun 09 10:43:27 volumio volumio[1139]: info: CoreCommandRouter::volumioPushState Jun 09 10:43:27 volumio volumio[1139]: info: ControllerMpd::pushState Jun 09 10:43:27 volumio volumio[1139]: info: CoreCommandRouter::servicePushState Jun 09 10:43:27 volumio volumio[1139]: info: CorePlayQueue::getTrack 0 Jun 09 10:43:27 volumio volumio[1139]: verbose: STATE SERVICE {"status":"play","position":0,"seek":27606,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"96 Kbps","isStreaming":false,"title":"Pjotr Iljitsch Tchaikovsky - Méditation de Souvenir d'un lieu cher ","artist":"Swiss Classic F","album":null,"uri":"http://stream.srg-ssr.ch/srgssr/rsc_fr/aac/96","trackType":""} Jun 09 10:43:27 volumio volumio[1139]: verbose: CURRENT POSITION 0 Jun 09 10:43:27 volumio volumio[1139]: info: CoreStateMachine::syncState stateService play Jun 09 10:43:27 volumio volumio[1139]: info: CoreStateMachine::syncState currentStatus play Jun 09 10:43:27 volumio volumio[1139]: info: Received an update from plugin. extracting info from payload Jun 09 10:43:27 volumio volumio[1139]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Jun 09 10:43:27 volumio volumio[1139]: info: CoreStateMachine::pushState Jun 09 10:43:27 volumio volumio[1139]: info: CoreCommandRouter::volumioPushState Jun 09 10:43:27 volumio volumio[1139]: info: CoreStateMachine::pushState Jun 09 10:43:27 volumio volumio[1139]: info: CoreCommandRouter::volumioPushState Jun 09 10:43:27 volumio volumio[1139]: info: ------------------------------ 57ms Jun 09 10:43:27 volumio volumio[1139]: info: ------------------------------ 56ms Jun 09 10:43:27 volumio systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Jun 09 10:43:27 volumio dbus-daemon[623]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.61' (uid=0 pid=4651 comm="timedatectl show --property=NTPSynchronized --valu") Jun 09 10:43:27 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service... Jun 09 10:43:28 volumio dbus-daemon[623]: [system] Successfully activated service 'org.freedesktop.timedate1' Jun 09 10:43:28 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service. Jun 09 10:43:28 volumio setdatetime-helper.sh[4650]: Time is not synchronized. Attempting to sync... Jun 09 10:43:28 volumio sudo[4659]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Mon, 09 Jun 2025 01:43:29 GMT#015' Jun 09 10:43:28 volumio sudo[4659]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 09 10:43:29 volumio setdatetime-helper.sh[4660]: Mon Jun 9 10:43:29 KST 2025 Jun 09 10:43:29 volumio sudo[4659]: pam_unix(sudo:session): session closed for user root Jun 09 10:43:29 volumio setdatetime-helper.sh[4650]: Time synchronized successfully. Jun 09 10:43:29 volumio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Jun 09 10:43:29 volumio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Jun 09 10:43:38 volumio volumio[1139]: info: CoreCommandRouter::volumioStop Jun 09 10:43:38 volumio volumio[1139]: info: CoreStateMachine::stop Jun 09 10:43:38 volumio volumio[1139]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 09 10:43:38 volumio volumio[1139]: info: CoreStateMachine::stPlaybackTimer Jun 09 10:43:38 volumio volumio[1139]: info: CoreStateMachine::updateTrackBlock Jun 09 10:43:38 volumio volumio[1139]: info: CorePlayQueue::getTrackBlock Jun 09 10:43:38 volumio volumio[1139]: info: CoreStateMachine::pushState Jun 09 10:43:38 volumio volumio[1139]: info: CorePlayQueue::getTrack 0 Jun 09 10:43:38 volumio volumio[1139]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 09 10:43:38 volumio volumio[1139]: info: CoreCommandRouter::volumioPushState Jun 09 10:43:38 volumio volumio[1139]: info: CoreStateMachine::serviceStop Jun 09 10:43:38 volumio volumio[1139]: info: CorePlayQueue::getTrack 0 Jun 09 10:43:38 volumio volumio[1139]: info: CoreCommandRouter::serviceStop Jun 09 10:43:38 volumio volumio[1139]: info: [1749433418608] ControllerWebradio::stop Jun 09 10:43:38 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand stop Jun 09 10:43:38 volumio volumio[1139]: info: Jun 09 10:43:38 volumio volumio[1139]: ---------------------------- MPD announces state update: player Jun 09 10:43:38 volumio volumio[1139]: info: sendMpdCommand stop took 10 milliseconds Jun 09 10:43:38 volumio volumio[1139]: info: ControllerMpd::getState Jun 09 10:43:38 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand status Jun 09 10:43:38 volumio volumio[1139]: info: Jun 09 10:43:38 volumio volumio[1139]: ---------------------------- MPD announces state update: player Jun 09 10:43:38 volumio volumio[1139]: info: ControllerMpd::getState Jun 09 10:43:38 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand status Jun 09 10:43:38 volumio volumio[1139]: info: sendMpdCommand status took 2 milliseconds Jun 09 10:43:38 volumio volumio[1139]: info: sendMpdCommand status took 1 milliseconds Jun 09 10:43:38 volumio volumio[1139]: verbose: ControllerMpd::parseState Jun 09 10:43:38 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 09 10:43:38 volumio volumio[1139]: verbose: ControllerMpd::parseState Jun 09 10:43:38 volumio volumio[1139]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 09 10:43:38 volumio volumio[1139]: info: sendMpdCommand playlistinfo took 1 milliseconds Jun 09 10:43:38 volumio volumio[1139]: info: sendMpdCommand playlistinfo took 2 milliseconds Jun 09 10:43:38 volumio volumio[1139]: verbose: ControllerMpd::parseTrackInfo Jun 09 10:43:38 volumio volumio[1139]: verbose: ControllerMpd::parseTrackInfo Jun 09 10:43:38 volumio volumio[1139]: info: ControllerMpd::pushState Jun 09 10:43:38 volumio volumio[1139]: info: CoreCommandRouter::servicePushState Jun 09 10:43:38 volumio volumio[1139]: info: CoreStateMachine::pushState Jun 09 10:43:38 volumio volumio[1139]: info: CorePlayQueue::getTrack 0 Jun 09 10:43:38 volumio volumio[1139]: info: CoreCommandRouter::volumioPushState Jun 09 10:43:38 volumio volumio[1139]: info: CorePlayQueue::getTrack 0 Jun 09 10:43:38 volumio volumio[1139]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Jun 09 10:43:38 volumio volumio[1139]: info: ControllerMpd::pushState Jun 09 10:43:38 volumio volumio[1139]: info: CoreCommandRouter::servicePushState Jun 09 10:43:38 volumio volumio[1139]: info: CoreStateMachine::pushState Jun 09 10:43:38 volumio volumio[1139]: info: CorePlayQueue::getTrack 0 Jun 09 10:43:38 volumio volumio[1139]: info: CoreCommandRouter::volumioPushState Jun 09 10:43:38 volumio volumio[1139]: info: CorePlayQueue::getTrack 0 Jun 09 10:43:38 volumio volumio[1139]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Jun 09 10:43:38 volumio volumio[1139]: info: ------------------------------ 30ms Jun 09 10:43:38 volumio volumio[1139]: info: ------------------------------ 30ms Jun 09 10:43:50 volumio volumio[1139]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Jun 09 10:43:50 volumio volumio[1139]: info: READ Jun 09 10:43:50 volumio volumio[1139]: Use XMLElement.setAttribute instead Jun 09 10:43:50 volumio volumio[1139]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 09 10:43:50 volumio volumio[1139]: TypeError: children[i].attr(...).value is not a function Jun 09 10:43:50 volumio volumio[1139]: at /volumio/app/plugins/music_service/webradio/index.js:286:47 Jun 09 10:43:50 volumio volumio[1139]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Jun 09 10:43:50 volumio volumio[1139]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 09 10:43:51 volumio sudo[4705]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-06-09 10:42' Jun 09 10:43:51 volumio sudo[4705]: 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="ecd46641d85b721d58d1c7edd71dd0a358c8514c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat Jun 7 04:21:21 UTC 2025" VOLUMIO_VERSION="4.011" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="97f38114d6fd5ff4ce2816f49b632994"