Jun 03 12:28:01 volumio nmbd[953]: [2025/06/03 12:28:01.728389, 0] ../../source3/libsmb/nmblib.c:923(send_udp) Jun 03 12:28:01 volumio nmbd[953]: Packet send failed to 192.168.211.255(138) ERRNO=Network is unreachable Jun 03 12:28:02 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 03 12:28:03 volumio volumio[1045]: info: Disabling MyMusic plugin upnp_browser Jun 03 12:28:03 volumio volumio[1045]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesMedia Servers Jun 03 12:28:03 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 03 12:28:03 volumio volumio[1045]: info: Disabling plugin upnp_browser Jun 03 12:28:03 volumio volumio[1045]: info: Done. Jun 03 12:28:04 volumio volumio[1045]: info: Disabling MyMusic plugin airplay_emulation Jun 03 12:28:04 volumio volumio[1045]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesShairport-Sync Jun 03 12:28:04 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 03 12:28:04 volumio volumio[1045]: info: Disabling plugin airplay_emulation Jun 03 12:28:04 volumio volumio[1045]: info: Done. Jun 03 12:28:04 volumio sudo[4142]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop shairport-sync Jun 03 12:28:04 volumio sudo[4142]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 03 12:28:04 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jun 03 12:28:04 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jun 03 12:28:04 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jun 03 12:28:04 volumio systemd[1]: shairport-sync.service: Consumed 1.796s CPU time. Jun 03 12:28:04 volumio sudo[4142]: pam_unix(sudo:session): session closed for user root Jun 03 12:28:04 volumio volumio[1045]: info: Shairport-Sync Stopped Jun 03 12:28:06 volumio volumio[1045]: info: Disabling MyMusic plugin upnp Jun 03 12:28:06 volumio sudo[4145]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Jun 03 12:28:06 volumio sudo[4145]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jun 03 12:28:06 volumio systemd[1]: Stopping upmpdcli.service - UPnP Renderer front-end to MPD... Jun 03 12:28:06 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 03 12:28:10 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 03 12:28:14 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 03 12:28:16 volumio volumio[1045]: info: CoreCommandRouter::volumioGetState Jun 03 12:28:16 volumio volumio[1045]: info: CorePlayQueue::getTrack 0 Jun 03 12:28:17 volumio volumio[1045]: info: CoreCommandRouter::volumioGetQueue Jun 03 12:28:17 volumio volumio[1045]: info: CoreStateMachine::getQueue Jun 03 12:28:17 volumio volumio[1045]: info: CorePlayQueue::getQueue Jun 03 12:28:27 volumio volumio[1045]: info: CoreCommandRouter::volumioGetState Jun 03 12:28:27 volumio volumio[1045]: info: CorePlayQueue::getTrack 0 Jun 03 12:28:28 volumio systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Jun 03 12:28:28 volumio dbus-daemon[595]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.64' (uid=0 pid=4192 comm="timedatectl show --property=NTPSynchronized --valu") Jun 03 12:28:28 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service... Jun 03 12:28:28 volumio dbus-daemon[595]: [system] Successfully activated service 'org.freedesktop.timedate1' Jun 03 12:28:28 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service. Jun 03 12:28:28 volumio setdatetime-helper.sh[4191]: Time is not synchronized. Attempting to sync... Jun 03 12:28:29 volumio sudo[4200]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Tue, 03 Jun 2025 11:28:29 GMT#015' Jun 03 12:28:29 volumio sudo[4200]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 03 12:28:29 volumio setdatetime-helper.sh[4201]: Tue Jun 3 12:28:29 BST 2025 Jun 03 12:28:29 volumio systemd-journald[356]: Time jumped backwards, rotating. Jun 03 12:28:29 volumio setdatetime-helper.sh[4191]: Time synchronized successfully. Jun 03 12:28:29 volumio sudo[4200]: pam_unix(sudo:session): session closed for user root Jun 03 12:28:29 volumio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Jun 03 12:28:29 volumio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Jun 03 12:28:42 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Jun 03 12:28:42 volumio volumio[1045]: info: Preload queue cleared Jun 03 12:28:44 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Jun 03 12:28:44 volumio volumio[1045]: info: Preload queue cleared Jun 03 12:28:47 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Jun 03 12:28:47 volumio volumio[1045]: info: Preload queue cleared Jun 03 12:28:54 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Jun 03 12:28:54 volumio volumio[1045]: info: Getting BBC Radios Jun 03 12:28:54 volumio volumio[1045]: info: Preload queue cleared Jun 03 12:28:58 volumio systemd[1]: systemd-timedated.service: Deactivated successfully. Jun 03 12:28:59 volumio volumio[1045]: info: Preload queue cleared Jun 03 12:28:59 volumio volumio[1045]: info: CoreCommandRouter::volumioReplaceandPlayItems Jun 03 12:28:59 volumio volumio[1045]: info: CoreStateMachine::ClearQueue Jun 03 12:28:59 volumio volumio[1045]: info: CoreStateMachine::stop Jun 03 12:28:59 volumio volumio[1045]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 03 12:28:59 volumio volumio[1045]: info: CorePlayQueue::clearPlayQueue Jun 03 12:28:59 volumio volumio[1045]: info: CorePlayQueue::saveQueue Jun 03 12:28:59 volumio volumio[1045]: info: CoreCommandRouter::volumioPushQueue Jun 03 12:28:59 volumio volumio[1045]: info: CoreStateMachine::addQueueItems Jun 03 12:28:59 volumio volumio[1045]: info: CorePlayQueue::addQueueItems Jun 03 12:28:59 volumio volumio[1045]: info: Preload queue cleared Jun 03 12:28:59 volumio volumio[1045]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_23461179/live/ww/bbc_radio_three/bbc_radio_three.isml/bbc_radio_three-audio%3d128000.norewind.m3u8 Jun 03 12:28:59 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Jun 03 12:28:59 volumio volumio[1045]: info: CoreCommandRouter::volumioPushQueue Jun 03 12:28:59 volumio volumio[1045]: info: CorePlayQueue::saveQueue Jun 03 12:28:59 volumio volumio[1045]: info: CoreStateMachine::updateTrackBlock Jun 03 12:28:59 volumio volumio[1045]: info: CorePlayQueue::getTrackBlock Jun 03 12:28:59 volumio volumio[1045]: info: CoreCommandRouter::volumioPlay Jun 03 12:28:59 volumio volumio[1045]: info: CoreStateMachine::play index 0 Jun 03 12:28:59 volumio volumio[1045]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 03 12:28:59 volumio volumio[1045]: info: CoreStateMachine::stop Jun 03 12:28:59 volumio volumio[1045]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 03 12:28:59 volumio volumio[1045]: info: CoreStateMachine::play index undefined Jun 03 12:28:59 volumio volumio[1045]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 03 12:28:59 volumio volumio[1045]: info: CorePlayQueue::getTrack 0 Jun 03 12:28:59 volumio volumio[1045]: info: CoreStateMachine::startPlaybackTimer Jun 03 12:28:59 volumio volumio[1045]: info: CorePlayQueue::getTrack 0 Jun 03 12:28:59 volumio volumio[1045]: info: [1748950139590] ControllerWebradio::clearAddPlayTrack Jun 03 12:28:59 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand stop Jun 03 12:28:59 volumio volumio[1045]: info: sendMpdCommand stop took 9 milliseconds Jun 03 12:28:59 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand clear Jun 03 12:28:59 volumio volumio[1045]: info: Jun 03 12:28:59 volumio volumio[1045]: ---------------------------- MPD announces system playlist update Jun 03 12:28:59 volumio volumio[1045]: info: Ignoring MPD Status Update Jun 03 12:28:59 volumio volumio[1045]: info: sendMpdCommand clear took 2 milliseconds Jun 03 12:28:59 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand add "http://as-hls-ww-live.akamaized.net/pool_23461179/live/ww/bbc_radio_three/bbc_radio_three.isml/bbc_radio_three-audio%3d128000.norewind.m3u8" Jun 03 12:28:59 volumio volumio[1045]: error: updateQueue error: null Jun 03 12:28:59 volumio volumio[1045]: info: Jun 03 12:28:59 volumio volumio[1045]: ---------------------------- MPD announces system playlist update Jun 03 12:28:59 volumio volumio[1045]: info: Ignoring MPD Status Update Jun 03 12:28:59 volumio volumio[1045]: info: ------------------------------ 4ms Jun 03 12:28:59 volumio volumio[1045]: info: sendMpdCommand add "http://as-hls-ww-live.akamaized.net/pool_23461179/live/ww/bbc_radio_three/bbc_radio_three.isml/bbc_radio_three-audio%3d128000.norewind.m3u8" took 3 milliseconds Jun 03 12:28:59 volumio volumio[1045]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 03 12:28:59 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand play Jun 03 12:28:59 volumio volumio[1045]: info: ------------------------------ 3ms Jun 03 12:28:59 volumio volumio[1045]: info: sendMpdCommand play took 3 milliseconds Jun 03 12:28:59 volumio nmbd[953]: [2025/06/03 12:28:59.864806, 0] ../../source3/libsmb/nmblib.c:923(send_udp) Jun 03 12:28:59 volumio nmbd[953]: Packet send failed to 192.168.211.255(138) ERRNO=Network is unreachable Jun 03 12:29:00 volumio volumio[1045]: info: Jun 03 12:29:00 volumio volumio[1045]: ---------------------------- MPD announces state update: player Jun 03 12:29:00 volumio volumio[1045]: info: ControllerMpd::getState Jun 03 12:29:00 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand status Jun 03 12:29:00 volumio volumio[1045]: info: sendMpdCommand status took 24 milliseconds Jun 03 12:29:00 volumio volumio[1045]: verbose: ControllerMpd::parseState Jun 03 12:29:00 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 03 12:29:00 volumio volumio[1045]: info: Jun 03 12:29:00 volumio volumio[1045]: ---------------------------- MPD announces state update: player Jun 03 12:29:00 volumio volumio[1045]: info: ControllerMpd::getState Jun 03 12:29:00 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand status Jun 03 12:29:00 volumio volumio[1045]: info: sendMpdCommand playlistinfo took 2 milliseconds Jun 03 12:29:00 volumio volumio[1045]: verbose: ControllerMpd::parseTrackInfo Jun 03 12:29:00 volumio volumio[1045]: info: ControllerMpd::pushState Jun 03 12:29:00 volumio volumio[1045]: info: CoreCommandRouter::servicePushState Jun 03 12:29:00 volumio volumio[1045]: info: CorePlayQueue::getTrack 0 Jun 03 12:29:00 volumio volumio[1045]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"bbc_radio_three-audio%3d128000.norewind.m3u8","artist":null,"album":null,"uri":"http://as-hls-ww-live.akamaized.net/pool_23461179/live/ww/bbc_radio_three/bbc_radio_three.isml/bbc_radio_three-audio%3d128000.norewind.m3u8","trackType":"m3u8"} Jun 03 12:29:00 volumio volumio[1045]: verbose: CURRENT POSITION 0 Jun 03 12:29:00 volumio volumio[1045]: info: CoreStateMachine::syncState stateService play Jun 03 12:29:00 volumio volumio[1045]: info: CoreStateMachine::syncState currentStatus stop Jun 03 12:29:00 volumio volumio[1045]: info: ------------------------------ 34ms Jun 03 12:29:00 volumio volumio[1045]: info: sendMpdCommand status took 6 milliseconds Jun 03 12:29:00 volumio volumio[1045]: verbose: ControllerMpd::parseState Jun 03 12:29:00 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 03 12:29:00 volumio volumio[1045]: info: sendMpdCommand playlistinfo took 1 milliseconds Jun 03 12:29:00 volumio volumio[1045]: verbose: ControllerMpd::parseTrackInfo Jun 03 12:29:00 volumio volumio[1045]: info: ControllerMpd::pushState Jun 03 12:29:00 volumio volumio[1045]: info: CoreCommandRouter::servicePushState Jun 03 12:29:00 volumio volumio[1045]: info: CorePlayQueue::getTrack 0 Jun 03 12:29:00 volumio volumio[1045]: verbose: STATE SERVICE {"status":"play","position":0,"seek":989,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"bbc_radio_three-audio%3d128000.norewind.m3u8","artist":null,"album":null,"uri":"http://as-hls-ww-live.akamaized.net/pool_23461179/live/ww/bbc_radio_three/bbc_radio_three.isml/bbc_radio_three-audio%3d128000.norewind.m3u8","trackType":"m3u8"} Jun 03 12:29:00 volumio volumio[1045]: verbose: CURRENT POSITION 0 Jun 03 12:29:00 volumio volumio[1045]: info: CoreStateMachine::syncState stateService play Jun 03 12:29:00 volumio volumio[1045]: info: CoreStateMachine::syncState currentStatus play Jun 03 12:29:00 volumio volumio[1045]: info: Received an update from plugin. extracting info from payload Jun 03 12:29:00 volumio volumio[1045]: info: CoreStateMachine::pushState Jun 03 12:29:00 volumio volumio[1045]: info: CorePlayQueue::getTrack 0 Jun 03 12:29:00 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 03 12:29:00 volumio volumio[1045]: info: CoreCommandRouter::volumioPushState Jun 03 12:29:00 volumio volumio[1045]: info: CoreStateMachine::pushState Jun 03 12:29:00 volumio volumio[1045]: info: CoreCommandRouter::volumioPushState Jun 03 12:29:00 volumio volumio[1045]: info: ------------------------------ 24ms Jun 03 12:29:08 volumio volumio[1045]: info: Preload queue cleared Jun 03 12:29:08 volumio volumio[1045]: info: CoreCommandRouter::volumioReplaceandPlayItems Jun 03 12:29:08 volumio volumio[1045]: info: CoreStateMachine::ClearQueue Jun 03 12:29:08 volumio volumio[1045]: info: CoreStateMachine::stop Jun 03 12:29:08 volumio volumio[1045]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 03 12:29:08 volumio volumio[1045]: info: CoreStateMachine::stPlaybackTimer Jun 03 12:29:08 volumio volumio[1045]: info: CoreStateMachine::updateTrackBlock Jun 03 12:29:08 volumio volumio[1045]: info: CorePlayQueue::getTrackBlock Jun 03 12:29:08 volumio volumio[1045]: info: CoreStateMachine::pushState Jun 03 12:29:08 volumio volumio[1045]: info: CorePlayQueue::getTrack 0 Jun 03 12:29:08 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 03 12:29:08 volumio volumio[1045]: info: CoreCommandRouter::volumioPushState Jun 03 12:29:08 volumio volumio[1045]: info: CoreStateMachine::serviceStop Jun 03 12:29:08 volumio volumio[1045]: info: CorePlayQueue::getTrack 0 Jun 03 12:29:08 volumio volumio[1045]: info: CoreCommandRouter::serviceStop Jun 03 12:29:08 volumio volumio[1045]: info: [1748950148194] ControllerWebradio::stop Jun 03 12:29:08 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand stop Jun 03 12:29:08 volumio volumio[1045]: info: CorePlayQueue::clearPlayQueue Jun 03 12:29:08 volumio volumio[1045]: info: CorePlayQueue::saveQueue Jun 03 12:29:08 volumio volumio[1045]: info: CoreCommandRouter::volumioPushQueue Jun 03 12:29:08 volumio volumio[1045]: info: CoreStateMachine::addQueueItems Jun 03 12:29:08 volumio volumio[1045]: info: CorePlayQueue::addQueueItems Jun 03 12:29:08 volumio volumio[1045]: info: Preload queue cleared Jun 03 12:29:08 volumio volumio[1045]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_23461179/live/ww/bbc_radio_three/bbc_radio_three.isml/bbc_radio_three-audio%3d128000.norewind.m3u8 Jun 03 12:29:08 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Jun 03 12:29:08 volumio volumio[1045]: info: CoreCommandRouter::volumioPushQueue Jun 03 12:29:08 volumio volumio[1045]: info: CorePlayQueue::saveQueue Jun 03 12:29:08 volumio volumio[1045]: info: CoreStateMachine::updateTrackBlock Jun 03 12:29:08 volumio volumio[1045]: info: CorePlayQueue::getTrackBlock Jun 03 12:29:08 volumio volumio[1045]: info: CoreCommandRouter::volumioPlay Jun 03 12:29:08 volumio volumio[1045]: info: CoreStateMachine::play index 0 Jun 03 12:29:08 volumio volumio[1045]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 03 12:29:08 volumio volumio[1045]: info: CoreStateMachine::stop Jun 03 12:29:08 volumio volumio[1045]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 03 12:29:08 volumio volumio[1045]: info: CoreStateMachine::play index undefined Jun 03 12:29:08 volumio volumio[1045]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 03 12:29:08 volumio volumio[1045]: info: CorePlayQueue::getTrack 0 Jun 03 12:29:08 volumio volumio[1045]: info: CoreStateMachine::startPlaybackTimer Jun 03 12:29:08 volumio volumio[1045]: info: CorePlayQueue::getTrack 0 Jun 03 12:29:08 volumio volumio[1045]: info: [1748950148205] ControllerWebradio::clearAddPlayTrack Jun 03 12:29:08 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand stop Jun 03 12:29:08 volumio volumio[1045]: info: Jun 03 12:29:08 volumio volumio[1045]: ---------------------------- MPD announces state update: player Jun 03 12:29:08 volumio volumio[1045]: info: sendMpdCommand stop took 159 milliseconds Jun 03 12:29:08 volumio volumio[1045]: info: ControllerMpd::getState Jun 03 12:29:08 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand status Jun 03 12:29:08 volumio volumio[1045]: info: sendMpdCommand stop took 149 milliseconds Jun 03 12:29:08 volumio volumio[1045]: info: sendMpdCommand status took 1 milliseconds Jun 03 12:29:08 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand clear Jun 03 12:29:08 volumio volumio[1045]: verbose: ControllerMpd::parseState Jun 03 12:29:08 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 03 12:29:08 volumio volumio[1045]: info: Jun 03 12:29:08 volumio volumio[1045]: ---------------------------- MPD announces system playlist update Jun 03 12:29:08 volumio volumio[1045]: info: Ignoring MPD Status Update Jun 03 12:29:08 volumio volumio[1045]: info: sendMpdCommand clear took 1 milliseconds Jun 03 12:29:08 volumio volumio[1045]: info: sendMpdCommand playlistinfo took 1 milliseconds Jun 03 12:29:08 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand add "http://as-hls-ww-live.akamaized.net/pool_23461179/live/ww/bbc_radio_three/bbc_radio_three.isml/bbc_radio_three-audio%3d128000.norewind.m3u8" Jun 03 12:29:08 volumio volumio[1045]: verbose: ControllerMpd::parseTrackInfo Jun 03 12:29:08 volumio volumio[1045]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Jun 03 12:29:08 volumio volumio[1045]: info: ------------------------------ 4ms Jun 03 12:29:08 volumio volumio[1045]: error: updateQueue error: null Jun 03 12:29:08 volumio volumio[1045]: info: Jun 03 12:29:08 volumio volumio[1045]: ---------------------------- MPD announces system playlist update Jun 03 12:29:08 volumio volumio[1045]: info: Ignoring MPD Status Update Jun 03 12:29:08 volumio volumio[1045]: info: ------------------------------ 3ms Jun 03 12:29:08 volumio volumio[1045]: info: sendMpdCommand add "http://as-hls-ww-live.akamaized.net/pool_23461179/live/ww/bbc_radio_three/bbc_radio_three.isml/bbc_radio_three-audio%3d128000.norewind.m3u8" took 2 milliseconds Jun 03 12:29:08 volumio volumio[1045]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 03 12:29:08 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand play Jun 03 12:29:08 volumio volumio[1045]: info: ------------------------------ 2ms Jun 03 12:29:08 volumio volumio[1045]: info: sendMpdCommand play took 1 milliseconds Jun 03 12:29:08 volumio volumio[1045]: info: Jun 03 12:29:08 volumio volumio[1045]: ---------------------------- MPD announces state update: player Jun 03 12:29:08 volumio volumio[1045]: info: ControllerMpd::getState Jun 03 12:29:08 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand status Jun 03 12:29:08 volumio volumio[1045]: info: Jun 03 12:29:08 volumio volumio[1045]: ---------------------------- MPD announces state update: player Jun 03 12:29:08 volumio volumio[1045]: info: sendMpdCommand status took 13 milliseconds Jun 03 12:29:08 volumio volumio[1045]: info: ControllerMpd::getState Jun 03 12:29:08 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand status Jun 03 12:29:08 volumio volumio[1045]: verbose: ControllerMpd::parseState Jun 03 12:29:08 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 03 12:29:08 volumio volumio[1045]: info: sendMpdCommand status took 1 milliseconds Jun 03 12:29:08 volumio volumio[1045]: info: sendMpdCommand playlistinfo took 1 milliseconds Jun 03 12:29:08 volumio volumio[1045]: verbose: ControllerMpd::parseState Jun 03 12:29:08 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 03 12:29:08 volumio volumio[1045]: verbose: ControllerMpd::parseTrackInfo Jun 03 12:29:08 volumio volumio[1045]: info: ControllerMpd::pushState Jun 03 12:29:08 volumio volumio[1045]: info: CoreCommandRouter::servicePushState Jun 03 12:29:08 volumio volumio[1045]: info: CorePlayQueue::getTrack 0 Jun 03 12:29:08 volumio volumio[1045]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"bbc_radio_three-audio%3d128000.norewind.m3u8","artist":null,"album":null,"uri":"http://as-hls-ww-live.akamaized.net/pool_23461179/live/ww/bbc_radio_three/bbc_radio_three.isml/bbc_radio_three-audio%3d128000.norewind.m3u8","trackType":"m3u8"} Jun 03 12:29:08 volumio volumio[1045]: verbose: CURRENT POSITION 0 Jun 03 12:29:08 volumio volumio[1045]: info: CoreStateMachine::syncState stateService play Jun 03 12:29:08 volumio volumio[1045]: info: CoreStateMachine::syncState currentStatus stop Jun 03 12:29:08 volumio volumio[1045]: info: ------------------------------ 18ms Jun 03 12:29:08 volumio volumio[1045]: info: sendMpdCommand playlistinfo took 1 milliseconds Jun 03 12:29:08 volumio volumio[1045]: verbose: ControllerMpd::parseTrackInfo Jun 03 12:29:08 volumio volumio[1045]: info: ControllerMpd::pushState Jun 03 12:29:08 volumio volumio[1045]: info: CoreCommandRouter::servicePushState Jun 03 12:29:08 volumio volumio[1045]: info: CorePlayQueue::getTrack 0 Jun 03 12:29:08 volumio volumio[1045]: verbose: STATE SERVICE {"status":"play","position":0,"seek":989,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"bbc_radio_three-audio%3d128000.norewind.m3u8","artist":null,"album":null,"uri":"http://as-hls-ww-live.akamaized.net/pool_23461179/live/ww/bbc_radio_three/bbc_radio_three.isml/bbc_radio_three-audio%3d128000.norewind.m3u8","trackType":"m3u8"} Jun 03 12:29:08 volumio volumio[1045]: verbose: CURRENT POSITION 0 Jun 03 12:29:08 volumio volumio[1045]: info: CoreStateMachine::syncState stateService play Jun 03 12:29:08 volumio volumio[1045]: info: CoreStateMachine::syncState currentStatus play Jun 03 12:29:08 volumio volumio[1045]: info: Received an update from plugin. extracting info from payload Jun 03 12:29:08 volumio volumio[1045]: info: CoreStateMachine::pushState Jun 03 12:29:08 volumio volumio[1045]: info: CorePlayQueue::getTrack 0 Jun 03 12:29:08 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 03 12:29:08 volumio volumio[1045]: info: CoreCommandRouter::volumioPushState Jun 03 12:29:08 volumio volumio[1045]: info: CoreStateMachine::pushState Jun 03 12:29:08 volumio volumio[1045]: info: CoreCommandRouter::volumioPushState Jun 03 12:29:08 volumio volumio[1045]: info: ------------------------------ 21ms Jun 03 12:29:09 volumio ntpd[797]: PROTO: 81.179.123.60 unlink local addr 192.168.1.122 -> Jun 03 12:29:22 volumio volumio[1045]: info: Preload queue cleared Jun 03 12:29:22 volumio volumio[1045]: info: CoreCommandRouter::volumioReplaceandPlayItems Jun 03 12:29:22 volumio volumio[1045]: info: CoreStateMachine::ClearQueue Jun 03 12:29:22 volumio volumio[1045]: info: CoreStateMachine::stop Jun 03 12:29:22 volumio volumio[1045]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 03 12:29:22 volumio volumio[1045]: info: CoreStateMachine::stPlaybackTimer Jun 03 12:29:22 volumio volumio[1045]: info: CoreStateMachine::updateTrackBlock Jun 03 12:29:22 volumio volumio[1045]: info: CorePlayQueue::getTrackBlock Jun 03 12:29:22 volumio volumio[1045]: info: CoreStateMachine::pushState Jun 03 12:29:22 volumio volumio[1045]: info: CorePlayQueue::getTrack 0 Jun 03 12:29:22 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 03 12:29:22 volumio volumio[1045]: info: CoreCommandRouter::volumioPushState Jun 03 12:29:22 volumio volumio[1045]: info: CoreStateMachine::serviceStop Jun 03 12:29:22 volumio volumio[1045]: info: CorePlayQueue::getTrack 0 Jun 03 12:29:22 volumio volumio[1045]: info: CoreCommandRouter::serviceStop Jun 03 12:29:22 volumio volumio[1045]: info: [1748950162984] ControllerWebradio::stop Jun 03 12:29:22 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand stop Jun 03 12:29:22 volumio volumio[1045]: info: CorePlayQueue::clearPlayQueue Jun 03 12:29:22 volumio volumio[1045]: info: CorePlayQueue::saveQueue Jun 03 12:29:22 volumio volumio[1045]: info: CoreCommandRouter::volumioPushQueue Jun 03 12:29:22 volumio volumio[1045]: info: CoreStateMachine::addQueueItems Jun 03 12:29:22 volumio volumio[1045]: info: CorePlayQueue::addQueueItems Jun 03 12:29:22 volumio volumio[1045]: info: Preload queue cleared Jun 03 12:29:22 volumio volumio[1045]: info: Adding Item to queue: http://as-hls-ww-live.akamaized.net/pool_74208725/live/ww/bbc_radio_two/bbc_radio_two.isml/bbc_radio_two-audio%3d96000.m3u8 Jun 03 12:29:22 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Jun 03 12:29:22 volumio volumio[1045]: info: CoreCommandRouter::volumioPushQueue Jun 03 12:29:22 volumio volumio[1045]: info: CorePlayQueue::saveQueue Jun 03 12:29:22 volumio volumio[1045]: info: CoreStateMachine::updateTrackBlock Jun 03 12:29:22 volumio volumio[1045]: info: CorePlayQueue::getTrackBlock Jun 03 12:29:22 volumio volumio[1045]: info: CoreCommandRouter::volumioPlay Jun 03 12:29:22 volumio volumio[1045]: info: CoreStateMachine::play index 0 Jun 03 12:29:22 volumio volumio[1045]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 03 12:29:22 volumio volumio[1045]: info: CoreStateMachine::stop Jun 03 12:29:22 volumio volumio[1045]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 03 12:29:22 volumio volumio[1045]: info: CoreStateMachine::play index undefined Jun 03 12:29:22 volumio volumio[1045]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 03 12:29:22 volumio volumio[1045]: info: CorePlayQueue::getTrack 0 Jun 03 12:29:22 volumio volumio[1045]: info: CoreStateMachine::startPlaybackTimer Jun 03 12:29:22 volumio volumio[1045]: info: CorePlayQueue::getTrack 0 Jun 03 12:29:22 volumio volumio[1045]: info: [1748950162997] ControllerWebradio::clearAddPlayTrack Jun 03 12:29:22 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand stop Jun 03 12:29:23 volumio volumio[1045]: info: Jun 03 12:29:23 volumio volumio[1045]: ---------------------------- MPD announces state update: player Jun 03 12:29:23 volumio volumio[1045]: info: sendMpdCommand stop took 18 milliseconds Jun 03 12:29:23 volumio volumio[1045]: info: ControllerMpd::getState Jun 03 12:29:23 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand status Jun 03 12:29:23 volumio volumio[1045]: info: sendMpdCommand stop took 5 milliseconds Jun 03 12:29:23 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand clear Jun 03 12:29:23 volumio volumio[1045]: info: Jun 03 12:29:23 volumio volumio[1045]: ---------------------------- MPD announces system playlist update Jun 03 12:29:23 volumio volumio[1045]: info: Ignoring MPD Status Update Jun 03 12:29:23 volumio volumio[1045]: info: sendMpdCommand status took 3 milliseconds Jun 03 12:29:23 volumio volumio[1045]: info: sendMpdCommand clear took 2 milliseconds Jun 03 12:29:23 volumio volumio[1045]: verbose: ControllerMpd::parseState Jun 03 12:29:23 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 03 12:29:23 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand add "http://as-hls-ww-live.akamaized.net/pool_74208725/live/ww/bbc_radio_two/bbc_radio_two.isml/bbc_radio_two-audio%3d96000.m3u8" Jun 03 12:29:23 volumio volumio[1045]: error: updateQueue error: null Jun 03 12:29:23 volumio volumio[1045]: info: Jun 03 12:29:23 volumio volumio[1045]: ---------------------------- MPD announces system playlist update Jun 03 12:29:23 volumio volumio[1045]: info: Ignoring MPD Status Update Jun 03 12:29:23 volumio volumio[1045]: info: ------------------------------ 3ms Jun 03 12:29:23 volumio volumio[1045]: info: sendMpdCommand playlistinfo took 2 milliseconds Jun 03 12:29:23 volumio volumio[1045]: info: sendMpdCommand add "http://as-hls-ww-live.akamaized.net/pool_74208725/live/ww/bbc_radio_two/bbc_radio_two.isml/bbc_radio_two-audio%3d96000.m3u8" took 2 milliseconds Jun 03 12:29:23 volumio volumio[1045]: verbose: ControllerMpd::parseTrackInfo Jun 03 12:29:23 volumio volumio[1045]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 03 12:29:23 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand play Jun 03 12:29:23 volumio volumio[1045]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Jun 03 12:29:23 volumio volumio[1045]: info: ------------------------------ 6ms Jun 03 12:29:23 volumio volumio[1045]: info: ------------------------------ 3ms Jun 03 12:29:23 volumio volumio[1045]: info: sendMpdCommand play took 1 milliseconds Jun 03 12:29:23 volumio volumio[1045]: info: Jun 03 12:29:23 volumio volumio[1045]: ---------------------------- MPD announces state update: player Jun 03 12:29:23 volumio volumio[1045]: info: ControllerMpd::getState Jun 03 12:29:23 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand status Jun 03 12:29:23 volumio volumio[1045]: info: Jun 03 12:29:23 volumio volumio[1045]: ---------------------------- MPD announces state update: player Jun 03 12:29:23 volumio volumio[1045]: info: sendMpdCommand status took 16 milliseconds Jun 03 12:29:23 volumio volumio[1045]: info: ControllerMpd::getState Jun 03 12:29:23 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand status Jun 03 12:29:23 volumio volumio[1045]: verbose: ControllerMpd::parseState Jun 03 12:29:23 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 03 12:29:23 volumio volumio[1045]: info: sendMpdCommand status took 2 milliseconds Jun 03 12:29:23 volumio volumio[1045]: info: sendMpdCommand playlistinfo took 2 milliseconds Jun 03 12:29:23 volumio volumio[1045]: verbose: ControllerMpd::parseState Jun 03 12:29:23 volumio volumio[1045]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 03 12:29:23 volumio volumio[1045]: verbose: ControllerMpd::parseTrackInfo Jun 03 12:29:23 volumio volumio[1045]: info: ControllerMpd::pushState Jun 03 12:29:23 volumio volumio[1045]: info: CoreCommandRouter::servicePushState Jun 03 12:29:23 volumio volumio[1045]: info: CorePlayQueue::getTrack 0 Jun 03 12:29:23 volumio volumio[1045]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"bbc_radio_two-audio%3d96000.m3u8","artist":null,"album":null,"uri":"http://as-hls-ww-live.akamaized.net/pool_74208725/live/ww/bbc_radio_two/bbc_radio_two.isml/bbc_radio_two-audio%3d96000.m3u8","trackType":"m3u8"} Jun 03 12:29:23 volumio volumio[1045]: verbose: CURRENT POSITION 0 Jun 03 12:29:23 volumio volumio[1045]: info: CoreStateMachine::syncState stateService play Jun 03 12:29:23 volumio volumio[1045]: info: CoreStateMachine::syncState currentStatus stop Jun 03 12:29:23 volumio volumio[1045]: info: ------------------------------ 23ms Jun 03 12:29:23 volumio volumio[1045]: info: sendMpdCommand playlistinfo took 3 milliseconds Jun 03 12:29:23 volumio volumio[1045]: verbose: ControllerMpd::parseTrackInfo Jun 03 12:29:23 volumio volumio[1045]: info: ControllerMpd::pushState Jun 03 12:29:23 volumio volumio[1045]: info: CoreCommandRouter::servicePushState Jun 03 12:29:23 volumio volumio[1045]: info: CorePlayQueue::getTrack 0 Jun 03 12:29:23 volumio volumio[1045]: verbose: STATE SERVICE {"status":"play","position":0,"seek":989,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"bbc_radio_two-audio%3d96000.m3u8","artist":null,"album":null,"uri":"http://as-hls-ww-live.akamaized.net/pool_74208725/live/ww/bbc_radio_two/bbc_radio_two.isml/bbc_radio_two-audio%3d96000.m3u8","trackType":"m3u8"} Jun 03 12:29:23 volumio volumio[1045]: verbose: CURRENT POSITION 0 Jun 03 12:29:23 volumio volumio[1045]: info: CoreStateMachine::syncState stateService play Jun 03 12:29:23 volumio volumio[1045]: info: CoreStateMachine::syncState currentStatus play Jun 03 12:29:23 volumio volumio[1045]: info: Received an update from plugin. extracting info from payload Jun 03 12:29:23 volumio volumio[1045]: info: CoreStateMachine::pushState Jun 03 12:29:23 volumio volumio[1045]: info: CorePlayQueue::getTrack 0 Jun 03 12:29:23 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 03 12:29:23 volumio volumio[1045]: info: CoreCommandRouter::volumioPushState Jun 03 12:29:23 volumio volumio[1045]: info: CoreStateMachine::pushState Jun 03 12:29:23 volumio volumio[1045]: info: CoreCommandRouter::volumioPushState Jun 03 12:29:23 volumio volumio[1045]: info: ------------------------------ 26ms Jun 03 12:29:25 volumio ntpd[797]: CLOCK: time stepped by 0.945730 Jun 03 12:29:25 volumio ntpd[797]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Jun 03 12:29:30 volumio systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Jun 03 12:29:30 volumio dbus-daemon[595]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.66' (uid=0 pid=4303 comm="timedatectl show --property=NTPSynchronized --valu") Jun 03 12:29:30 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service... Jun 03 12:29:30 volumio dbus-daemon[595]: [system] Successfully activated service 'org.freedesktop.timedate1' Jun 03 12:29:30 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service. Jun 03 12:29:30 volumio setdatetime-helper.sh[4302]: Time is not synchronized. Attempting to sync... Jun 03 12:29:30 volumio sudo[4311]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Tue, 03 Jun 2025 11:29:30 GMT#015' Jun 03 12:29:30 volumio sudo[4311]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jun 03 12:29:30 volumio setdatetime-helper.sh[4312]: Tue Jun 3 12:29:30 BST 2025 Jun 03 12:29:30 volumio systemd-journald[356]: Time jumped backwards, rotating. Jun 03 12:29:30 volumio sudo[4311]: pam_unix(sudo:session): session closed for user root Jun 03 12:29:30 volumio setdatetime-helper.sh[4302]: Time synchronized successfully. Jun 03 12:29:30 volumio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Jun 03 12:29:30 volumio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Jun 03 12:29:35 volumio volumio[1045]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Jun 03 12:29:35 volumio volumio[1045]: Use XMLElement.setAttribute instead Jun 03 12:29:35 volumio volumio[1045]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 03 12:29:35 volumio volumio[1045]: TypeError: children[i].attr(...).value is not a function Jun 03 12:29:35 volumio volumio[1045]: at /volumio/app/plugins/music_service/webradio/index.js:428:46 Jun 03 12:29:35 volumio volumio[1045]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Jun 03 12:29:35 volumio volumio[1045]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 03 12:29:36 volumio sudo[4329]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-06-03 12:28' Jun 03 12:29:36 volumio sudo[4329]: 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="a42e8353c03f8616e137cf760ea618e88c395461" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon Jun 2 16:20:51 UTC 2025" VOLUMIO_VERSION="4.010" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="f51ec0ad91e50bdfdb863e902a9e8fa2"