Feb 24 00:21:00 volumio volumio5-onboarding[7214]: time=2026-02-24T00:21:00.440+05:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.50:58788 Feb 24 00:21:07 volumio volumio5-onboarding[7214]: failed to bootstrap state: failed to get music providers: could not get available plugins: could not get available plugins: context deadline exceeded Feb 24 00:21:07 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Feb 24 00:21:07 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Feb 24 00:21:07 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 57. Feb 24 00:21:07 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 24 00:21:07 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 24 00:21:07 volumio volumio5-onboarding[7272]: time=2026-02-24T00:21:07.385+05:00 level=INFO msg="running volumio5-device-gateway" version=30d1950e+CHANGES buildDate=2026-01-29T13:10:08Z Feb 24 00:21:07 volumio volumio[2781]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 5 Feb 24 00:21:07 volumio volumio[2781]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 5 Feb 24 00:21:07 volumio volumio[2781]: info: Received Get System Info Feb 24 00:21:07 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 00:21:07 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 00:21:07 volumio volumio[2781]: info: Discovery: Getting this device information Feb 24 00:21:07 volumio volumio[2781]: info: CoreCommandRouter::volumioGetState Feb 24 00:21:07 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 00:21:07 volumio volumio5-onboarding[7272]: time=2026-02-24T00:21:07.449+05:00 level=INFO msg="system info for bff68a8718d95d75e912e96b6def4d85" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.096 Feb 24 00:21:07 volumio volumio[2781]: info: Received Get System Info Feb 24 00:21:07 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 00:21:07 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 00:21:07 volumio volumio[2781]: info: Discovery: Getting this device information Feb 24 00:21:07 volumio volumio[2781]: info: CoreCommandRouter::volumioGetState Feb 24 00:21:07 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 00:21:07 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 24 00:21:07 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 24 00:21:07 volumio volumio5-onboarding[7272]: time=2026-02-24T00:21:07.513+05:00 level=INFO msg="enabling local network discovery" Feb 24 00:21:07 volumio volumio5-onboarding[7272]: time=2026-02-24T00:21:07.596+05:00 level=INFO msg="bootstrapping state" hasInternet=true Feb 24 00:21:07 volumio volumio[2781]: info: Received Get System Info Feb 24 00:21:07 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 00:21:07 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 00:21:07 volumio volumio[2781]: info: Discovery: Getting this device information Feb 24 00:21:07 volumio volumio[2781]: info: CoreCommandRouter::volumioGetState Feb 24 00:21:07 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 00:21:07 volumio volumio-remote-updater[2063]: Test mode disabled Feb 24 00:21:07 volumio volumio-remote-updater[2063]: Alpha mode disabled Feb 24 00:21:07 volumio volumio-remote-updater[2063]: Alpha legacy test mode disabled Feb 24 00:21:07 volumio volumio[2781]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Feb 24 00:21:07 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 24 00:21:07 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 24 00:21:07 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 24 00:21:07 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 24 00:21:08 volumio volumio5-onboarding[7272]: time=2026-02-24T00:21:08.139+05:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.50:58830 Feb 24 00:21:10 volumio volumio5-onboarding[7272]: time=2026-02-24T00:21:10.941+05:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.1.50:58830 Feb 24 00:21:10 volumio volumio5-onboarding[7272]: time=2026-02-24T00:21:10.942+05:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.1.50:58830 Feb 24 00:21:10 volumio volumio5-onboarding[7272]: time=2026-02-24T00:21:10.954+05:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.50:54094 Feb 24 00:21:16 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Feb 24 00:21:16 volumio volumio[2781]: info: Preload queue cleared Feb 24 00:21:18 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Feb 24 00:21:19 volumio volumio[2781]: error: Cannot download Available plugins list: Error: ESOCKETTIMEDOUT Feb 24 00:21:19 volumio volumio[2781]: info: Preload queue cleared Feb 24 00:21:21 volumio volumio5-onboarding[7272]: time=2026-02-24T00:21:21.459+05:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.50:57804 Feb 24 00:21:31 volumio volumio5-onboarding[7272]: time=2026-02-24T00:21:31.969+05:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.50:54946 Feb 24 00:21:37 volumio volumio5-onboarding[7272]: failed to bootstrap state: failed to get music providers: could not get available plugins: could not get available plugins: context deadline exceeded Feb 24 00:21:37 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Feb 24 00:21:37 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Feb 24 00:21:37 volumio volumio[2781]: info: VolumeController::SetAlsaVolume52 Feb 24 00:21:37 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:37 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 00:21:37 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:37 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 58. Feb 24 00:21:37 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 24 00:21:37 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 24 00:21:37 volumio volumio5-onboarding[7331]: time=2026-02-24T00:21:37.918+05:00 level=INFO msg="running volumio5-device-gateway" version=30d1950e+CHANGES buildDate=2026-01-29T13:10:08Z Feb 24 00:21:37 volumio volumio[2781]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 5 Feb 24 00:21:37 volumio volumio[2781]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 5 Feb 24 00:21:37 volumio volumio[2781]: info: Received Get System Info Feb 24 00:21:37 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 00:21:37 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 00:21:37 volumio volumio[2781]: info: Discovery: Getting this device information Feb 24 00:21:37 volumio volumio[2781]: info: CoreCommandRouter::volumioGetState Feb 24 00:21:37 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 00:21:38 volumio volumio5-onboarding[7331]: time=2026-02-24T00:21:38.002+05:00 level=INFO msg="system info for bff68a8718d95d75e912e96b6def4d85" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.096 Feb 24 00:21:38 volumio volumio[2781]: info: Received Get System Info Feb 24 00:21:38 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 00:21:38 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 00:21:38 volumio volumio[2781]: info: Discovery: Getting this device information Feb 24 00:21:38 volumio volumio[2781]: info: CoreCommandRouter::volumioGetState Feb 24 00:21:38 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 00:21:38 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 24 00:21:38 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 24 00:21:38 volumio volumio5-onboarding[7331]: time=2026-02-24T00:21:38.070+05:00 level=INFO msg="enabling local network discovery" Feb 24 00:21:38 volumio volumio5-onboarding[7331]: time=2026-02-24T00:21:38.155+05:00 level=INFO msg="bootstrapping state" hasInternet=true Feb 24 00:21:38 volumio volumio[2781]: info: Received Get System Info Feb 24 00:21:38 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 00:21:38 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 00:21:38 volumio volumio[2781]: info: Discovery: Getting this device information Feb 24 00:21:38 volumio volumio[2781]: info: CoreCommandRouter::volumioGetState Feb 24 00:21:38 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 00:21:38 volumio volumio-remote-updater[2063]: Test mode disabled Feb 24 00:21:38 volumio volumio-remote-updater[2063]: Alpha mode disabled Feb 24 00:21:38 volumio volumio-remote-updater[2063]: Alpha legacy test mode disabled Feb 24 00:21:38 volumio volumio[2781]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Feb 24 00:21:38 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 24 00:21:38 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 24 00:21:38 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 24 00:21:38 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 24 00:21:38 volumio volumio5-onboarding[7331]: time=2026-02-24T00:21:38.657+05:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.50:54990 Feb 24 00:21:42 volumio volumio5-onboarding[7331]: time=2026-02-24T00:21:42.460+05:00 level=INFO msg="WebSocket connection closed" component=conn/ws remoteAddr=192.168.1.50:54990 Feb 24 00:21:42 volumio volumio5-onboarding[7331]: time=2026-02-24T00:21:42.461+05:00 level=INFO msg="connection to address closed" component=conn/multi addr=192.168.1.50:54990 Feb 24 00:21:42 volumio volumio5-onboarding[7331]: time=2026-02-24T00:21:42.466+05:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.50:51586 Feb 24 00:21:43 volumio volumio[2781]: info: Preload queue cleared Feb 24 00:21:43 volumio volumio[2781]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 24 00:21:43 volumio volumio[2781]: info: CoreStateMachine::ClearQueue Feb 24 00:21:43 volumio volumio[2781]: info: CoreStateMachine::stop Feb 24 00:21:43 volumio volumio[2781]: info: CoreStateMachine::serviceStop Feb 24 00:21:43 volumio volumio[2781]: info: CoreCommandRouter::serviceStop Feb 24 00:21:43 volumio volumio[2781]: info: Airplay Stop Feb 24 00:21:43 volumio volumio[2781]: info: Stopping Airplay Playback and sending pause command to client via USR2 Feb 24 00:21:43 volumio volumio[2781]: info: CorePlayQueue::clearPlayQueue Feb 24 00:21:43 volumio volumio[2781]: info: CorePlayQueue::saveQueue Feb 24 00:21:43 volumio volumio[2781]: info: CoreCommandRouter::volumioPushQueue Feb 24 00:21:43 volumio volumio[2781]: info: CoreStateMachine::addQueueItems Feb 24 00:21:43 volumio volumio[2781]: info: CorePlayQueue::addQueueItems Feb 24 00:21:43 volumio volumio[2781]: info: Preload queue cleared Feb 24 00:21:43 volumio volumio[2781]: info: Adding Item to queue: http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996 Feb 24 00:21:43 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Feb 24 00:21:43 volumio volumio[2781]: info: CoreCommandRouter::volumioPushQueue Feb 24 00:21:43 volumio volumio[2781]: info: CorePlayQueue::saveQueue Feb 24 00:21:43 volumio volumio[2781]: info: CoreStateMachine::updateTrackBlock Feb 24 00:21:43 volumio volumio[2781]: info: CorePlayQueue::getTrackBlock Feb 24 00:21:43 volumio volumio[2781]: info: CoreCommandRouter::volumioPlay Feb 24 00:21:43 volumio volumio[2781]: verbose: UNSET VOLATILE: Service: airplay_emulation Feb 24 00:21:43 volumio volumio[2781]: info: Stopping Airplay Playback and sending pause command to client via USR2 Feb 24 00:21:43 volumio volumio[2781]: info: CoreStateMachine::play index 0 Feb 24 00:21:43 volumio volumio[2781]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 00:21:43 volumio volumio[2781]: info: CoreStateMachine::stop Feb 24 00:21:43 volumio volumio[2781]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 00:21:43 volumio volumio[2781]: info: CoreStateMachine::stPlaybackTimer Feb 24 00:21:43 volumio volumio[2781]: info: CoreStateMachine::updateTrackBlock Feb 24 00:21:43 volumio volumio[2781]: info: CorePlayQueue::getTrackBlock Feb 24 00:21:43 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:43 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:43 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 00:21:43 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:43 volumio volumio[2781]: info: CoreStateMachine::serviceStop Feb 24 00:21:43 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:43 volumio volumio[2781]: info: CoreCommandRouter::serviceStop Feb 24 00:21:43 volumio volumio[2781]: info: [1771874503618] ControllerWebradio::stop Feb 24 00:21:43 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand stop Feb 24 00:21:43 volumio volumio[2781]: info: sendMpdCommand stop took 19 milliseconds Feb 24 00:21:43 volumio volumio[2781]: info: CoreStateMachine::play index undefined Feb 24 00:21:43 volumio volumio[2781]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 00:21:43 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:43 volumio volumio[2781]: info: CoreStateMachine::startPlaybackTimer Feb 24 00:21:43 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:43 volumio volumio[2781]: info: [1771874503648] ControllerWebradio::clearAddPlayTrack Feb 24 00:21:43 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand stop Feb 24 00:21:43 volumio volumio[2781]: info: sendMpdCommand stop took 5 milliseconds Feb 24 00:21:43 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand clear Feb 24 00:21:43 volumio volumio[2781]: info: Feb 24 00:21:43 volumio volumio[2781]: ---------------------------- MPD announces system playlist update Feb 24 00:21:43 volumio volumio[2781]: info: Ignoring MPD Status Update Feb 24 00:21:43 volumio volumio[2781]: info: sendMpdCommand clear took 9 milliseconds Feb 24 00:21:43 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" Feb 24 00:21:43 volumio sudo[7361]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/kill -USR2 3632 Feb 24 00:21:43 volumio sudo[7361]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 24 00:21:43 volumio volumio[2781]: info: Feb 24 00:21:43 volumio volumio[2781]: ---------------------------- MPD announces system playlist update Feb 24 00:21:43 volumio volumio[2781]: info: Ignoring MPD Status Update Feb 24 00:21:43 volumio volumio[2781]: info: Feb 24 00:21:43 volumio volumio[2781]: ---------------------------- MPD announces system playlist update Feb 24 00:21:43 volumio volumio[2781]: info: Ignoring MPD Status Update Feb 24 00:21:43 volumio sudo[7361]: pam_unix(sudo:session): session closed for user root Feb 24 00:21:43 volumio volumio[2781]: error: updateQueue error: null Feb 24 00:21:43 volumio volumio[2781]: info: ------------------------------ 50ms Feb 24 00:21:43 volumio shairport-sync[6936]: {"time":1771874296089,"response":"startAirplayPlayback Success"} Feb 24 00:21:43 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=12/USR2 Feb 24 00:21:43 volumio systemd[1]: shairport-sync.service: Failed with result 'signal'. Feb 24 00:21:43 volumio systemd[1]: shairport-sync.service: Consumed 10min 27.401s CPU time. Feb 24 00:21:43 volumio sudo[7363]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/kill -USR2 3632 Feb 24 00:21:43 volumio sudo[7363]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 24 00:21:43 volumio volumio[2781]: info: Shairport-Sync paused with USR2 Feb 24 00:21:43 volumio sudo[7363]: pam_unix(sudo:session): session closed for user root Feb 24 00:21:43 volumio volumio[2781]: info: Cannot execute Shairport-sync USR2 kill: Error: Command failed: /usr/bin/sudo /bin/kill -USR2 $(pidof shairport-sync) Feb 24 00:21:43 volumio volumio[2781]: /bin/kill: (3632): No such process Feb 24 00:21:44 volumio volumio[2781]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" took 449 milliseconds Feb 24 00:21:44 volumio volumio[2781]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 24 00:21:44 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand play Feb 24 00:21:44 volumio volumio[2781]: info: Feb 24 00:21:44 volumio volumio[2781]: ---------------------------- MPD announces system playlist update Feb 24 00:21:44 volumio volumio[2781]: info: Ignoring MPD Status Update Feb 24 00:21:44 volumio volumio[2781]: info: ------------------------------ 457ms Feb 24 00:21:44 volumio volumio[2781]: info: ------------------------------ 452ms Feb 24 00:21:44 volumio volumio[2781]: info: Feb 24 00:21:44 volumio volumio[2781]: ---------------------------- MPD announces system playlist update Feb 24 00:21:44 volumio volumio[2781]: info: Ignoring MPD Status Update Feb 24 00:21:44 volumio volumio[2781]: info: Feb 24 00:21:44 volumio volumio[2781]: ---------------------------- MPD announces system playlist update Feb 24 00:21:44 volumio volumio[2781]: info: Ignoring MPD Status Update Feb 24 00:21:44 volumio volumio[2781]: info: sendMpdCommand play took 23 milliseconds Feb 24 00:21:44 volumio volumio[2781]: info: ------------------------------ 23ms Feb 24 00:21:44 volumio volumio[2781]: info: ------------------------------ 7ms Feb 24 00:21:44 volumio volumio[2781]: info: ------------------------------ 5ms Feb 24 00:21:44 volumio volumio[2781]: info: Restarting Shairport-Sync after stop Feb 24 00:21:44 volumio sudo[7372]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 24 00:21:44 volumio sudo[7372]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 24 00:21:44 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 24 00:21:44 volumio sudo[7372]: pam_unix(sudo:session): session closed for user root Feb 24 00:21:44 volumio volumio[2781]: info: Shairport-Sync retarted Feb 24 00:21:45 volumio volumio[2781]: info: Feb 24 00:21:45 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:21:45 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:21:45 volumio volumio[2781]: info: Feb 24 00:21:45 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:21:45 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:21:45 volumio volumio[2781]: info: Feb 24 00:21:45 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:21:45 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:21:45 volumio volumio[2781]: info: Feb 24 00:21:45 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:21:45 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:21:45 volumio volumio[2781]: info: Feb 24 00:21:45 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:21:45 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:21:45 volumio volumio[2781]: info: Feb 24 00:21:45 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:21:45 volumio volumio[2781]: info: sendMpdCommand status took 21 milliseconds Feb 24 00:21:45 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:21:45 volumio volumio[2781]: info: sendMpdCommand status took 20 milliseconds Feb 24 00:21:45 volumio volumio[2781]: info: sendMpdCommand status took 17 milliseconds Feb 24 00:21:45 volumio volumio[2781]: info: sendMpdCommand status took 13 milliseconds Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:21:45 volumio volumio[2781]: info: sendMpdCommand status took 27 milliseconds Feb 24 00:21:45 volumio volumio[2781]: info: sendMpdCommand status took 20 milliseconds Feb 24 00:21:45 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 13 milliseconds Feb 24 00:21:45 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 10 milliseconds Feb 24 00:21:45 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 9 milliseconds Feb 24 00:21:45 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 9 milliseconds Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:21:45 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:45 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:45 volumio volumio[2781]: 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":"antenne","artist":"(#1 - 5628/500000) ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Feb 24 00:21:45 volumio volumio[2781]: verbose: CURRENT POSITION 0 Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::syncState stateService play Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::syncState currentStatus stop Feb 24 00:21:45 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:45 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:45 volumio volumio[2781]: 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":"antenne","artist":"(#1 - 5628/500000) ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Feb 24 00:21:45 volumio volumio[2781]: verbose: CURRENT POSITION 0 Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::syncState stateService play Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::syncState currentStatus play Feb 24 00:21:45 volumio volumio[2781]: info: Received an update from plugin. extracting info from payload Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:45 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:45 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:45 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:45 volumio volumio[2781]: 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":"antenne","artist":"(#1 - 5628/500000) ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Feb 24 00:21:45 volumio volumio[2781]: verbose: CURRENT POSITION 0 Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::syncState stateService play Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::syncState currentStatus play Feb 24 00:21:45 volumio volumio[2781]: info: Received an update from plugin. extracting info from payload Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:45 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:45 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:45 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:45 volumio volumio[2781]: 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":"antenne","artist":"(#1 - 5628/500000) ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Feb 24 00:21:45 volumio volumio[2781]: verbose: CURRENT POSITION 0 Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::syncState stateService play Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::syncState currentStatus play Feb 24 00:21:45 volumio volumio[2781]: info: Received an update from plugin. extracting info from payload Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:45 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:45 volumio volumio[2781]: info: ------------------------------ 106ms Feb 24 00:21:45 volumio volumio[2781]: info: ------------------------------ 114ms Feb 24 00:21:45 volumio volumio[2781]: info: ------------------------------ 111ms Feb 24 00:21:45 volumio volumio[2781]: info: ------------------------------ 108ms Feb 24 00:21:45 volumio volumio[2781]: info: Feb 24 00:21:45 volumio volumio[2781]: ---------------------------- MPD announces system playlist update Feb 24 00:21:45 volumio volumio[2781]: info: Ignoring MPD Status Update Feb 24 00:21:45 volumio volumio[2781]: info: Feb 24 00:21:45 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:21:45 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 84 milliseconds Feb 24 00:21:45 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 84 milliseconds Feb 24 00:21:45 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:21:45 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:45 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:45 volumio volumio[2781]: 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":"antenne","artist":"(#1 - 5628/500000) ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Feb 24 00:21:45 volumio volumio[2781]: verbose: CURRENT POSITION 0 Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::syncState stateService play Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::syncState currentStatus play Feb 24 00:21:45 volumio volumio[2781]: info: Received an update from plugin. extracting info from payload Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:45 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:45 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:45 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:45 volumio volumio[2781]: 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":"antenne","artist":"(#1 - 5628/500000) ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Feb 24 00:21:45 volumio volumio[2781]: verbose: CURRENT POSITION 0 Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::syncState stateService play Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::syncState currentStatus play Feb 24 00:21:45 volumio volumio[2781]: info: Received an update from plugin. extracting info from payload Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:45 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:45 volumio volumio[2781]: info: ------------------------------ 153ms Feb 24 00:21:45 volumio volumio[2781]: info: ------------------------------ 152ms Feb 24 00:21:45 volumio volumio[2781]: info: Feb 24 00:21:45 volumio volumio[2781]: ---------------------------- MPD announces system playlist update Feb 24 00:21:45 volumio volumio[2781]: info: Ignoring MPD Status Update Feb 24 00:21:45 volumio volumio[2781]: info: Feb 24 00:21:45 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:21:45 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:21:45 volumio volumio[2781]: info: Feb 24 00:21:45 volumio volumio[2781]: ---------------------------- MPD announces system playlist update Feb 24 00:21:45 volumio volumio[2781]: info: Ignoring MPD Status Update Feb 24 00:21:45 volumio volumio[2781]: info: Feb 24 00:21:45 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:21:45 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:21:45 volumio volumio[2781]: info: ------------------------------ 81ms Feb 24 00:21:45 volumio volumio[2781]: info: sendMpdCommand status took 77 milliseconds Feb 24 00:21:45 volumio volumio[2781]: info: ------------------------------ 41ms Feb 24 00:21:45 volumio volumio[2781]: info: sendMpdCommand status took 40 milliseconds Feb 24 00:21:45 volumio volumio[2781]: info: ------------------------------ 38ms Feb 24 00:21:45 volumio volumio[2781]: info: sendMpdCommand status took 36 milliseconds Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:21:45 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 10 milliseconds Feb 24 00:21:45 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 10 milliseconds Feb 24 00:21:45 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 10 milliseconds Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:21:45 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:21:45 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:45 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:45 volumio volumio[2781]: verbose: STATE SERVICE {"status":"play","position":0,"seek":888,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Benson Boone - Sorry I'm Here For Someone Else","artist":"ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Feb 24 00:21:45 volumio volumio[2781]: verbose: CURRENT POSITION 0 Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::syncState stateService play Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::syncState currentStatus play Feb 24 00:21:45 volumio volumio[2781]: info: Received an update from plugin. extracting info from payload Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:45 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:45 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:45 volumio volumio[2781]: verbose: STATE SERVICE {"status":"play","position":0,"seek":979,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Benson Boone - Sorry I'm Here For Someone Else","artist":"ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Feb 24 00:21:45 volumio volumio[2781]: verbose: CURRENT POSITION 0 Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::syncState stateService play Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::syncState currentStatus play Feb 24 00:21:45 volumio volumio[2781]: info: Received an update from plugin. extracting info from payload Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:45 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:45 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:45 volumio volumio[2781]: verbose: STATE SERVICE {"status":"play","position":0,"seek":979,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Benson Boone - Sorry I'm Here For Someone Else","artist":"ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Feb 24 00:21:45 volumio volumio[2781]: verbose: CURRENT POSITION 0 Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::syncState stateService play Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::syncState currentStatus play Feb 24 00:21:45 volumio volumio[2781]: info: Received an update from plugin. extracting info from payload Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:45 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:45 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:45 volumio volumio[2781]: info: ------------------------------ 135ms Feb 24 00:21:45 volumio volumio[2781]: info: ------------------------------ 96ms Feb 24 00:21:45 volumio volumio[2781]: info: ------------------------------ 93ms Feb 24 00:21:47 volumio shairport-sync[7374]: warning: alsa: error -16 ("Device or resource busy") opening alsa device "volumio". Feb 24 00:21:47 volumio volumio[2781]: info: Airplay started streaming, receiving metadatas Feb 24 00:21:47 volumio volumio[2781]: info: CoreCommandRouter::volumioStop Feb 24 00:21:47 volumio volumio[2781]: info: CoreStateMachine::stop Feb 24 00:21:47 volumio volumio[2781]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 00:21:47 volumio volumio[2781]: info: CoreStateMachine::stPlaybackTimer Feb 24 00:21:47 volumio volumio[2781]: info: CoreStateMachine::updateTrackBlock Feb 24 00:21:47 volumio volumio[2781]: info: CorePlayQueue::getTrackBlock Feb 24 00:21:47 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:47 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:47 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 00:21:47 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:47 volumio volumio[2781]: info: CoreStateMachine::serviceStop Feb 24 00:21:47 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:47 volumio volumio[2781]: info: CoreCommandRouter::serviceStop Feb 24 00:21:47 volumio volumio[2781]: info: [1771874507844] ControllerWebradio::stop Feb 24 00:21:47 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand stop Feb 24 00:21:47 volumio volumio[2781]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 00:21:47 volumio volumio[2781]: info: Airplay started streaming, receiving metadatas Feb 24 00:21:47 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:47 volumio volumio[2781]: info: CoreCommandRouter::volumioStop Feb 24 00:21:47 volumio volumio[2781]: info: CoreStateMachine::stop Feb 24 00:21:47 volumio volumio[2781]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 00:21:47 volumio volumio[2781]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 00:21:47 volumio volumio[2781]: info: Airplay started streaming, receiving metadatas Feb 24 00:21:47 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:47 volumio volumio[2781]: info: CoreCommandRouter::volumioStop Feb 24 00:21:47 volumio volumio[2781]: info: CoreStateMachine::stop Feb 24 00:21:47 volumio volumio[2781]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 00:21:47 volumio volumio[2781]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 00:21:47 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:47 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:47 volumio volumio[2781]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received airplay_emulation Feb 24 00:21:47 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:47 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:47 volumio volumio[2781]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received airplay_emulation Feb 24 00:21:47 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:47 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:47 volumio volumio[2781]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received airplay_emulation Feb 24 00:21:47 volumio volumio[2781]: info: Feb 24 00:21:47 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:21:47 volumio volumio[2781]: info: sendMpdCommand stop took 25 milliseconds Feb 24 00:21:47 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:21:47 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:21:47 volumio volumio[2781]: info: Feb 24 00:21:47 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:21:47 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:21:47 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:21:47 volumio volumio[2781]: info: Feb 24 00:21:47 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:21:47 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:21:47 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:21:47 volumio volumio[2781]: info: sendMpdCommand status took 10 milliseconds Feb 24 00:21:47 volumio volumio[2781]: info: sendMpdCommand status took 7 milliseconds Feb 24 00:21:47 volumio volumio[2781]: info: sendMpdCommand status took 4 milliseconds Feb 24 00:21:47 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:21:47 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:21:47 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:21:47 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:21:47 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:21:47 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:21:47 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 7 milliseconds Feb 24 00:21:47 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 5 milliseconds Feb 24 00:21:47 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 4 milliseconds Feb 24 00:21:47 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:21:47 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:21:47 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:21:47 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:21:47 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:47 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:47 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:47 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:47 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:47 volumio volumio[2781]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Feb 24 00:21:47 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:21:47 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:47 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:47 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:47 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:47 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:47 volumio volumio[2781]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Feb 24 00:21:47 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:21:47 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:47 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:47 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:47 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:47 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:47 volumio volumio[2781]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Feb 24 00:21:47 volumio shairport-sync[7404]: % Total % Received % Xferd Average Speed Time Time Time Current Feb 24 00:21:47 volumio shairport-sync[7404]: Dload Upload Total Spent Left Speed Feb 24 00:21:47 volumio volumio[2781]: info: ------------------------------ 60ms Feb 24 00:21:47 volumio volumio[2781]: info: ------------------------------ 56ms Feb 24 00:21:47 volumio volumio[2781]: info: ------------------------------ 53ms Feb 24 00:21:47 volumio shairport-sync[7404]: [79B blob data] Feb 24 00:21:47 volumio shairport-sync[7409]: % Total % Received % Xferd Average Speed Time Time Time Current Feb 24 00:21:47 volumio shairport-sync[7409]: Dload Upload Total Spent Left Speed Feb 24 00:21:47 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:47 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:47 volumio volumio[2781]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received airplay_emulation Feb 24 00:21:47 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:47 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:47 volumio volumio[2781]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received airplay_emulation Feb 24 00:21:47 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:47 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:47 volumio volumio[2781]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received airplay_emulation Feb 24 00:21:47 volumio volumio[2781]: info: Feb 24 00:21:47 volumio volumio[2781]: ---------------------------- Client requests AirplayActive Feb 24 00:21:47 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , setAirplayActive Feb 24 00:21:47 volumio shairport-sync[7409]: [79B blob data] Feb 24 00:21:47 volumio shairport-sync[7404]: [79B blob data] Feb 24 00:21:47 volumio volumio[2781]: info: Feb 24 00:21:47 volumio volumio[2781]: ---------------------------- Client requests Start Airplay PlaybackRoutine Feb 24 00:21:47 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , startAirplayPlayback Feb 24 00:21:47 volumio volumio[2781]: info: Airplay playback start Feb 24 00:21:47 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:47 volumio volumio[2781]: info: CoreCommandRouter::volumioStop Feb 24 00:21:47 volumio volumio[2781]: info: CoreStateMachine::stop Feb 24 00:21:47 volumio volumio[2781]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 00:21:47 volumio volumio[2781]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 00:21:47 volumio shairport-sync[7404]: {"time":1771874507963,"response":"airplayActive Success"} Feb 24 00:21:47 volumio shairport-sync[7409]: [79B blob data] Feb 24 00:21:48 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:48 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:48 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 00:21:48 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:48 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:48 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:48 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:48 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:48 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:48 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:48 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:48 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:48 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:49 volumio volumio[2781]: error: Cannot download Available plugins list: Error: ESOCKETTIMEDOUT Feb 24 00:21:52 volumio volumio5-onboarding[7331]: time=2026-02-24T00:21:52.978+05:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.50:36528 Feb 24 00:21:58 volumio volumio[2781]: info: Preload queue cleared Feb 24 00:21:58 volumio volumio[2781]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 24 00:21:58 volumio volumio[2781]: info: CoreStateMachine::ClearQueue Feb 24 00:21:58 volumio volumio[2781]: info: CoreStateMachine::stop Feb 24 00:21:58 volumio volumio[2781]: info: CoreStateMachine::serviceStop Feb 24 00:21:58 volumio volumio[2781]: info: CoreCommandRouter::serviceStop Feb 24 00:21:58 volumio volumio[2781]: info: Airplay Stop Feb 24 00:21:58 volumio volumio[2781]: info: Stopping Airplay Playback and sending pause command to client via USR2 Feb 24 00:21:58 volumio volumio[2781]: info: CorePlayQueue::clearPlayQueue Feb 24 00:21:58 volumio volumio[2781]: info: CorePlayQueue::saveQueue Feb 24 00:21:58 volumio volumio[2781]: info: CoreCommandRouter::volumioPushQueue Feb 24 00:21:58 volumio volumio[2781]: info: CoreStateMachine::addQueueItems Feb 24 00:21:58 volumio volumio[2781]: info: CorePlayQueue::addQueueItems Feb 24 00:21:58 volumio volumio[2781]: info: Preload queue cleared Feb 24 00:21:58 volumio volumio[2781]: info: Adding Item to queue: http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996 Feb 24 00:21:58 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Feb 24 00:21:58 volumio volumio[2781]: info: CoreCommandRouter::volumioPushQueue Feb 24 00:21:58 volumio volumio[2781]: info: CorePlayQueue::saveQueue Feb 24 00:21:58 volumio volumio[2781]: info: CoreStateMachine::updateTrackBlock Feb 24 00:21:58 volumio volumio[2781]: info: CorePlayQueue::getTrackBlock Feb 24 00:21:58 volumio volumio[2781]: info: CoreCommandRouter::volumioPlay Feb 24 00:21:58 volumio volumio[2781]: verbose: UNSET VOLATILE: Service: airplay_emulation Feb 24 00:21:58 volumio volumio[2781]: info: Stopping Airplay Playback and sending pause command to client via USR2 Feb 24 00:21:58 volumio volumio[2781]: info: CoreStateMachine::play index 0 Feb 24 00:21:58 volumio volumio[2781]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 00:21:58 volumio volumio[2781]: info: CoreStateMachine::stop Feb 24 00:21:58 volumio volumio[2781]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 00:21:58 volumio volumio[2781]: info: CoreStateMachine::stPlaybackTimer Feb 24 00:21:58 volumio volumio[2781]: info: CoreStateMachine::updateTrackBlock Feb 24 00:21:58 volumio volumio[2781]: info: CorePlayQueue::getTrackBlock Feb 24 00:21:58 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:58 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:58 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 00:21:58 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:58 volumio volumio[2781]: info: CoreStateMachine::serviceStop Feb 24 00:21:58 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:58 volumio volumio[2781]: info: CoreCommandRouter::serviceStop Feb 24 00:21:58 volumio volumio[2781]: info: [1771874518163] ControllerWebradio::stop Feb 24 00:21:58 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand stop Feb 24 00:21:58 volumio volumio[2781]: info: sendMpdCommand stop took 24 milliseconds Feb 24 00:21:58 volumio volumio[2781]: info: CoreStateMachine::play index undefined Feb 24 00:21:58 volumio volumio[2781]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 00:21:58 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:58 volumio volumio[2781]: info: CoreStateMachine::startPlaybackTimer Feb 24 00:21:58 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:58 volumio volumio[2781]: info: [1771874518190] ControllerWebradio::clearAddPlayTrack Feb 24 00:21:58 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand stop Feb 24 00:21:58 volumio volumio[2781]: info: sendMpdCommand stop took 2 milliseconds Feb 24 00:21:58 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand clear Feb 24 00:21:58 volumio volumio[2781]: info: Feb 24 00:21:58 volumio volumio[2781]: ---------------------------- MPD announces system playlist update Feb 24 00:21:58 volumio volumio[2781]: info: Ignoring MPD Status Update Feb 24 00:21:58 volumio volumio[2781]: info: sendMpdCommand clear took 3 milliseconds Feb 24 00:21:58 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" Feb 24 00:21:58 volumio volumio[2781]: info: Feb 24 00:21:58 volumio volumio[2781]: ---------------------------- MPD announces system playlist update Feb 24 00:21:58 volumio volumio[2781]: info: Ignoring MPD Status Update Feb 24 00:21:58 volumio volumio[2781]: info: Feb 24 00:21:58 volumio volumio[2781]: ---------------------------- MPD announces system playlist update Feb 24 00:21:58 volumio volumio[2781]: info: Ignoring MPD Status Update Feb 24 00:21:58 volumio sudo[7436]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/kill -USR2 7374 Feb 24 00:21:58 volumio volumio[2781]: error: updateQueue error: null Feb 24 00:21:58 volumio volumio[2781]: info: ------------------------------ 12ms Feb 24 00:21:58 volumio sudo[7436]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 24 00:21:58 volumio sudo[7436]: pam_unix(sudo:session): session closed for user root Feb 24 00:21:58 volumio volumio[2781]: info: Shairport-Sync paused with USR2 Feb 24 00:21:58 volumio shairport-sync[7409]: {"time":1771874507973,"response":"startAirplayPlayback Success"} Feb 24 00:21:58 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=12/USR2 Feb 24 00:21:58 volumio systemd[1]: shairport-sync.service: Failed with result 'signal'. Feb 24 00:21:58 volumio sudo[7437]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/kill -USR2 7374 Feb 24 00:21:58 volumio sudo[7437]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 24 00:21:58 volumio systemd[1]: shairport-sync.service: Consumed 2.227s CPU time. Feb 24 00:21:58 volumio sudo[7437]: pam_unix(sudo:session): session closed for user root Feb 24 00:21:58 volumio volumio[2781]: info: Cannot execute Shairport-sync USR2 kill: Error: Command failed: /usr/bin/sudo /bin/kill -USR2 $(pidof shairport-sync) Feb 24 00:21:58 volumio volumio[2781]: /bin/kill: (7374): No such process Feb 24 00:21:58 volumio volumio[2781]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" took 160 milliseconds Feb 24 00:21:58 volumio volumio[2781]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 24 00:21:58 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand play Feb 24 00:21:58 volumio volumio[2781]: info: Feb 24 00:21:58 volumio volumio[2781]: ---------------------------- MPD announces system playlist update Feb 24 00:21:58 volumio volumio[2781]: info: Ignoring MPD Status Update Feb 24 00:21:58 volumio volumio[2781]: info: ------------------------------ 161ms Feb 24 00:21:58 volumio volumio[2781]: info: ------------------------------ 159ms Feb 24 00:21:58 volumio volumio[2781]: info: Feb 24 00:21:58 volumio volumio[2781]: ---------------------------- MPD announces system playlist update Feb 24 00:21:58 volumio volumio[2781]: info: Ignoring MPD Status Update Feb 24 00:21:58 volumio volumio[2781]: info: Feb 24 00:21:58 volumio volumio[2781]: ---------------------------- MPD announces system playlist update Feb 24 00:21:58 volumio volumio[2781]: info: Ignoring MPD Status Update Feb 24 00:21:58 volumio volumio[2781]: info: sendMpdCommand play took 8 milliseconds Feb 24 00:21:58 volumio volumio[2781]: info: ------------------------------ 8ms Feb 24 00:21:58 volumio volumio[2781]: info: ------------------------------ 5ms Feb 24 00:21:58 volumio volumio[2781]: info: ------------------------------ 4ms Feb 24 00:21:59 volumio volumio[2781]: info: Restarting Shairport-Sync after stop Feb 24 00:21:59 volumio sudo[7444]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 24 00:21:59 volumio sudo[7444]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 24 00:21:59 volumio volumio[2781]: info: Feb 24 00:21:59 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:21:59 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:21:59 volumio volumio[2781]: info: Feb 24 00:21:59 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:21:59 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:21:59 volumio volumio[2781]: info: Feb 24 00:21:59 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:21:59 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:21:59 volumio volumio[2781]: info: Feb 24 00:21:59 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:21:59 volumio volumio[2781]: info: sendMpdCommand status took 22 milliseconds Feb 24 00:21:59 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:21:59 volumio volumio[2781]: info: sendMpdCommand status took 28 milliseconds Feb 24 00:21:59 volumio volumio[2781]: info: sendMpdCommand status took 28 milliseconds Feb 24 00:21:59 volumio volumio[2781]: info: sendMpdCommand status took 8 milliseconds Feb 24 00:21:59 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 7 milliseconds Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:21:59 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:59 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:59 volumio volumio[2781]: 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":"antenne","artist":"(#1 - 5628/500000) ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Feb 24 00:21:59 volumio volumio[2781]: verbose: CURRENT POSITION 0 Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::syncState stateService play Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::syncState currentStatus stop Feb 24 00:21:59 volumio volumio[2781]: info: ------------------------------ 39ms Feb 24 00:21:59 volumio volumio[2781]: info: Feb 24 00:21:59 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:21:59 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 24 00:21:59 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:21:59 volumio volumio[2781]: info: Feb 24 00:21:59 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:21:59 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:21:59 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 12 milliseconds Feb 24 00:21:59 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 12 milliseconds Feb 24 00:21:59 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 13 milliseconds Feb 24 00:21:59 volumio volumio[2781]: info: sendMpdCommand status took 7 milliseconds Feb 24 00:21:59 volumio volumio[2781]: info: sendMpdCommand status took 6 milliseconds Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:21:59 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:59 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:59 volumio volumio[2781]: 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":"antenne","artist":"(#1 - 5628/500000) ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Feb 24 00:21:59 volumio volumio[2781]: verbose: CURRENT POSITION 0 Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::syncState stateService play Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::syncState currentStatus play Feb 24 00:21:59 volumio volumio[2781]: info: Received an update from plugin. extracting info from payload Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:59 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:59 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:59 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:59 volumio volumio[2781]: 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":"antenne","artist":"(#1 - 5628/500000) ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Feb 24 00:21:59 volumio volumio[2781]: verbose: CURRENT POSITION 0 Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::syncState stateService play Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::syncState currentStatus play Feb 24 00:21:59 volumio volumio[2781]: info: Received an update from plugin. extracting info from payload Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:59 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:59 volumio sudo[7444]: pam_unix(sudo:session): session closed for user root Feb 24 00:21:59 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:59 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:59 volumio volumio[2781]: 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":"antenne","artist":"(#1 - 5628/500000) ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Feb 24 00:21:59 volumio volumio[2781]: verbose: CURRENT POSITION 0 Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::syncState stateService play Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::syncState currentStatus play Feb 24 00:21:59 volumio volumio[2781]: info: Received an update from plugin. extracting info from payload Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:59 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:59 volumio volumio[2781]: info: ------------------------------ 168ms Feb 24 00:21:59 volumio volumio[2781]: info: ------------------------------ 167ms Feb 24 00:21:59 volumio volumio[2781]: info: ------------------------------ 150ms Feb 24 00:21:59 volumio volumio[2781]: info: Feb 24 00:21:59 volumio volumio[2781]: ---------------------------- MPD announces system playlist update Feb 24 00:21:59 volumio volumio[2781]: info: Ignoring MPD Status Update Feb 24 00:21:59 volumio volumio[2781]: info: Feb 24 00:21:59 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:21:59 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:21:59 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 123 milliseconds Feb 24 00:21:59 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 122 milliseconds Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:21:59 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:59 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:59 volumio volumio[2781]: 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":"Benson Boone - Sorry I'm Here For Someone Else","artist":"ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Feb 24 00:21:59 volumio volumio[2781]: verbose: CURRENT POSITION 0 Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::syncState stateService play Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::syncState currentStatus play Feb 24 00:21:59 volumio volumio[2781]: info: Received an update from plugin. extracting info from payload Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:59 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:59 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:59 volumio volumio[2781]: 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":"Benson Boone - Sorry I'm Here For Someone Else","artist":"ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Feb 24 00:21:59 volumio volumio[2781]: verbose: CURRENT POSITION 0 Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::syncState stateService play Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::syncState currentStatus play Feb 24 00:21:59 volumio volumio[2781]: info: Received an update from plugin. extracting info from payload Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:59 volumio volumio[2781]: info: ------------------------------ 183ms Feb 24 00:21:59 volumio volumio[2781]: info: ------------------------------ 184ms Feb 24 00:21:59 volumio volumio[2781]: info: Feb 24 00:21:59 volumio volumio[2781]: ---------------------------- MPD announces system playlist update Feb 24 00:21:59 volumio volumio[2781]: info: Ignoring MPD Status Update Feb 24 00:21:59 volumio volumio[2781]: info: Feb 24 00:21:59 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:21:59 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:21:59 volumio volumio[2781]: info: Feb 24 00:21:59 volumio volumio[2781]: ---------------------------- MPD announces system playlist update Feb 24 00:21:59 volumio volumio[2781]: info: Ignoring MPD Status Update Feb 24 00:21:59 volumio volumio[2781]: info: Feb 24 00:21:59 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:21:59 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:21:59 volumio volumio[2781]: info: Shairport-Sync retarted Feb 24 00:21:59 volumio volumio[2781]: info: ------------------------------ 109ms Feb 24 00:21:59 volumio volumio[2781]: info: sendMpdCommand status took 108 milliseconds Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:21:59 volumio volumio[2781]: info: ------------------------------ 34ms Feb 24 00:21:59 volumio volumio[2781]: info: sendMpdCommand status took 35 milliseconds Feb 24 00:21:59 volumio volumio[2781]: info: ------------------------------ 34ms Feb 24 00:21:59 volumio volumio[2781]: info: sendMpdCommand status took 34 milliseconds Feb 24 00:21:59 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 28 milliseconds Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:21:59 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:59 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:59 volumio volumio[2781]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Benson Boone - Sorry I'm Here For Someone Else","artist":"ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Feb 24 00:21:59 volumio volumio[2781]: verbose: CURRENT POSITION 0 Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::syncState stateService play Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::syncState currentStatus play Feb 24 00:21:59 volumio volumio[2781]: info: Received an update from plugin. extracting info from payload Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:59 volumio volumio[2781]: info: ------------------------------ 170ms Feb 24 00:21:59 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 52 milliseconds Feb 24 00:21:59 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 52 milliseconds Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:21:59 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:21:59 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:59 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:59 volumio volumio[2781]: verbose: STATE SERVICE {"status":"play","position":0,"seek":983,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Benson Boone - Sorry I'm Here For Someone Else","artist":"ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Feb 24 00:21:59 volumio volumio[2781]: verbose: CURRENT POSITION 0 Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::syncState stateService play Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::syncState currentStatus play Feb 24 00:21:59 volumio volumio[2781]: info: Received an update from plugin. extracting info from payload Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:59 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:21:59 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:21:59 volumio volumio[2781]: verbose: STATE SERVICE {"status":"play","position":0,"seek":983,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Benson Boone - Sorry I'm Here For Someone Else","artist":"ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Feb 24 00:21:59 volumio volumio[2781]: verbose: CURRENT POSITION 0 Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::syncState stateService play Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::syncState currentStatus play Feb 24 00:21:59 volumio volumio[2781]: info: Received an update from plugin. extracting info from payload Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:21:59 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:21:59 volumio volumio[2781]: info: ------------------------------ 135ms Feb 24 00:21:59 volumio volumio[2781]: info: ------------------------------ 132ms Feb 24 00:22:03 volumio volumio5-onboarding[7331]: time=2026-02-24T00:22:03.480+05:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.50:55594 Feb 24 00:22:05 volumio volumio[2781]: info: VolumeController::SetAlsaVolume42 Feb 24 00:22:05 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:05 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 00:22:05 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:08 volumio volumio5-onboarding[7331]: failed to bootstrap state: failed to get music providers: could not get available plugins: could not get available plugins: context deadline exceeded Feb 24 00:22:08 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Feb 24 00:22:08 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Feb 24 00:22:08 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 59. Feb 24 00:22:08 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 24 00:22:08 volumio volumio[2781]: info: VolumeController::SetAlsaVolume17 Feb 24 00:22:08 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Feb 24 00:22:08 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:08 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 00:22:08 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:08 volumio volumio5-onboarding[7499]: time=2026-02-24T00:22:08.379+05:00 level=INFO msg="running volumio5-device-gateway" version=30d1950e+CHANGES buildDate=2026-01-29T13:10:08Z Feb 24 00:22:08 volumio volumio[2781]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 5 Feb 24 00:22:08 volumio volumio[2781]: info: Received Get System Info Feb 24 00:22:08 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 00:22:08 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 00:22:08 volumio volumio[2781]: info: Discovery: Getting this device information Feb 24 00:22:08 volumio volumio[2781]: info: CoreCommandRouter::volumioGetState Feb 24 00:22:08 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 00:22:08 volumio volumio[2781]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 5 Feb 24 00:22:08 volumio volumio5-onboarding[7499]: time=2026-02-24T00:22:08.443+05:00 level=INFO msg="system info for bff68a8718d95d75e912e96b6def4d85" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.096 Feb 24 00:22:08 volumio volumio[2781]: info: Received Get System Info Feb 24 00:22:08 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 00:22:08 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 00:22:08 volumio volumio[2781]: info: Discovery: Getting this device information Feb 24 00:22:08 volumio volumio[2781]: info: CoreCommandRouter::volumioGetState Feb 24 00:22:08 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 00:22:08 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 24 00:22:08 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 24 00:22:08 volumio volumio5-onboarding[7499]: time=2026-02-24T00:22:08.518+05:00 level=INFO msg="enabling local network discovery" Feb 24 00:22:08 volumio volumio5-onboarding[7499]: time=2026-02-24T00:22:08.604+05:00 level=INFO msg="bootstrapping state" hasInternet=true Feb 24 00:22:08 volumio volumio[2781]: info: Received Get System Info Feb 24 00:22:08 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 00:22:08 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 00:22:08 volumio volumio[2781]: info: Discovery: Getting this device information Feb 24 00:22:08 volumio volumio[2781]: info: CoreCommandRouter::volumioGetState Feb 24 00:22:08 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 00:22:08 volumio volumio-remote-updater[2063]: Test mode disabled Feb 24 00:22:08 volumio volumio-remote-updater[2063]: Alpha mode disabled Feb 24 00:22:08 volumio volumio-remote-updater[2063]: Alpha legacy test mode disabled Feb 24 00:22:08 volumio volumio[2781]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Feb 24 00:22:08 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 24 00:22:08 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 24 00:22:08 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 24 00:22:08 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 24 00:22:09 volumio volumio5-onboarding[7499]: time=2026-02-24T00:22:09.180+05:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.50:51200 Feb 24 00:22:09 volumio volumio[2781]: info: VolumeController::SetAlsaVolume36 Feb 24 00:22:09 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:09 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 00:22:09 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:10 volumio volumio[2781]: info: VolumeController::SetAlsaVolume50 Feb 24 00:22:10 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:10 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 00:22:10 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:11 volumio volumio[2781]: info: VolumeController::SetAlsaVolume41 Feb 24 00:22:11 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:11 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 00:22:11 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:18 volumio volumio5-onboarding[7499]: time=2026-02-24T00:22:18.984+05:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.50:51216 Feb 24 00:22:20 volumio volumio[2781]: error: Cannot download Available plugins list: Error: ESOCKETTIMEDOUT Feb 24 00:22:22 volumio volumio[2781]: info: Preload queue cleared Feb 24 00:22:22 volumio volumio[2781]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 24 00:22:22 volumio volumio[2781]: info: CoreStateMachine::ClearQueue Feb 24 00:22:22 volumio volumio[2781]: info: CoreStateMachine::stop Feb 24 00:22:22 volumio volumio[2781]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 00:22:22 volumio volumio[2781]: info: CoreStateMachine::stPlaybackTimer Feb 24 00:22:22 volumio volumio[2781]: info: CoreStateMachine::updateTrackBlock Feb 24 00:22:22 volumio volumio[2781]: info: CorePlayQueue::getTrackBlock Feb 24 00:22:22 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:22 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:22:22 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 00:22:22 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:22 volumio volumio[2781]: info: CoreStateMachine::serviceStop Feb 24 00:22:22 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:22:22 volumio volumio[2781]: info: CoreCommandRouter::serviceStop Feb 24 00:22:22 volumio volumio[2781]: info: [1771874542548] ControllerWebradio::stop Feb 24 00:22:22 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand stop Feb 24 00:22:22 volumio volumio[2781]: info: CorePlayQueue::clearPlayQueue Feb 24 00:22:22 volumio volumio[2781]: info: CorePlayQueue::saveQueue Feb 24 00:22:22 volumio volumio[2781]: info: CoreCommandRouter::volumioPushQueue Feb 24 00:22:22 volumio volumio[2781]: info: CoreStateMachine::addQueueItems Feb 24 00:22:22 volumio volumio[2781]: info: CorePlayQueue::addQueueItems Feb 24 00:22:22 volumio volumio[2781]: info: Preload queue cleared Feb 24 00:22:22 volumio volumio[2781]: info: Adding Item to queue: http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99568320 Feb 24 00:22:22 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Feb 24 00:22:22 volumio volumio[2781]: info: CoreCommandRouter::volumioPushQueue Feb 24 00:22:22 volumio volumio[2781]: info: CorePlayQueue::saveQueue Feb 24 00:22:22 volumio volumio[2781]: info: CoreStateMachine::updateTrackBlock Feb 24 00:22:22 volumio volumio[2781]: info: CorePlayQueue::getTrackBlock Feb 24 00:22:22 volumio volumio[2781]: info: CoreCommandRouter::volumioPlay Feb 24 00:22:22 volumio volumio[2781]: info: CoreStateMachine::play index 0 Feb 24 00:22:22 volumio volumio[2781]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 00:22:22 volumio volumio[2781]: info: CoreStateMachine::stop Feb 24 00:22:22 volumio volumio[2781]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 00:22:22 volumio volumio[2781]: info: CoreStateMachine::play index undefined Feb 24 00:22:22 volumio volumio[2781]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 00:22:22 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:22:22 volumio volumio[2781]: info: CoreStateMachine::startPlaybackTimer Feb 24 00:22:22 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:22:22 volumio volumio[2781]: info: [1771874542568] ControllerWebradio::clearAddPlayTrack Feb 24 00:22:22 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand stop Feb 24 00:22:22 volumio volumio[2781]: info: Feb 24 00:22:22 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:22:22 volumio volumio[2781]: info: sendMpdCommand stop took 26 milliseconds Feb 24 00:22:22 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:22:22 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:22:22 volumio volumio[2781]: info: sendMpdCommand stop took 7 milliseconds Feb 24 00:22:22 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand clear Feb 24 00:22:22 volumio volumio[2781]: info: Feb 24 00:22:22 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:22:22 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:22:22 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:22:22 volumio volumio[2781]: info: Feb 24 00:22:22 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:22:22 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:22:22 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:22:22 volumio volumio[2781]: info: Feb 24 00:22:22 volumio volumio[2781]: ---------------------------- MPD announces system playlist update Feb 24 00:22:22 volumio volumio[2781]: info: Ignoring MPD Status Update Feb 24 00:22:22 volumio volumio[2781]: info: sendMpdCommand status took 7 milliseconds Feb 24 00:22:22 volumio volumio[2781]: info: sendMpdCommand clear took 6 milliseconds Feb 24 00:22:22 volumio volumio[2781]: info: sendMpdCommand status took 5 milliseconds Feb 24 00:22:22 volumio volumio[2781]: info: sendMpdCommand status took 4 milliseconds Feb 24 00:22:22 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:22:22 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:22:22 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99568320" Feb 24 00:22:22 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:22:22 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:22:22 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:22:22 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:22:22 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:22 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:22:22 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 00:22:22 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:22 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:22:22 volumio volumio[2781]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Feb 24 00:22:22 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:22:22 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:22:22 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:22 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:22:22 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:22 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:22:22 volumio volumio[2781]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Feb 24 00:22:22 volumio volumio[2781]: info: ------------------------------ 26ms Feb 24 00:22:22 volumio volumio[2781]: info: ------------------------------ 25ms Feb 24 00:22:22 volumio volumio[2781]: info: Feb 24 00:22:22 volumio volumio[2781]: ---------------------------- MPD announces system playlist update Feb 24 00:22:22 volumio volumio[2781]: info: Ignoring MPD Status Update Feb 24 00:22:22 volumio volumio[2781]: info: Feb 24 00:22:22 volumio volumio[2781]: ---------------------------- MPD announces system playlist update Feb 24 00:22:22 volumio volumio[2781]: info: Ignoring MPD Status Update Feb 24 00:22:22 volumio volumio[2781]: error: updateQueue error: null Feb 24 00:22:22 volumio volumio[2781]: info: ------------------------------ 36ms Feb 24 00:22:22 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 35 milliseconds Feb 24 00:22:22 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:22:22 volumio volumio[2781]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Feb 24 00:22:22 volumio volumio[2781]: info: ------------------------------ 49ms Feb 24 00:22:22 volumio volumio[2781]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99568320" took 161 milliseconds Feb 24 00:22:22 volumio volumio[2781]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 24 00:22:22 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand play Feb 24 00:22:22 volumio volumio[2781]: info: Feb 24 00:22:22 volumio volumio[2781]: ---------------------------- MPD announces system playlist update Feb 24 00:22:22 volumio volumio[2781]: info: Ignoring MPD Status Update Feb 24 00:22:22 volumio volumio[2781]: info: ------------------------------ 143ms Feb 24 00:22:22 volumio volumio[2781]: info: ------------------------------ 142ms Feb 24 00:22:22 volumio volumio[2781]: info: Feb 24 00:22:22 volumio volumio[2781]: ---------------------------- MPD announces system playlist update Feb 24 00:22:22 volumio volumio[2781]: info: Ignoring MPD Status Update Feb 24 00:22:22 volumio volumio[2781]: info: Feb 24 00:22:22 volumio volumio[2781]: ---------------------------- MPD announces system playlist update Feb 24 00:22:22 volumio volumio[2781]: info: Ignoring MPD Status Update Feb 24 00:22:22 volumio volumio[2781]: info: sendMpdCommand play took 9 milliseconds Feb 24 00:22:22 volumio volumio[2781]: info: ------------------------------ 8ms Feb 24 00:22:22 volumio volumio[2781]: info: ------------------------------ 5ms Feb 24 00:22:22 volumio volumio[2781]: info: ------------------------------ 5ms Feb 24 00:22:24 volumio volumio[2781]: info: Feb 24 00:22:24 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:22:24 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:22:24 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:22:24 volumio volumio[2781]: info: Feb 24 00:22:24 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:22:24 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:22:24 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:22:24 volumio volumio[2781]: info: Feb 24 00:22:24 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:22:24 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:22:24 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:22:24 volumio volumio[2781]: info: sendMpdCommand status took 19 milliseconds Feb 24 00:22:24 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:22:24 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:22:24 volumio volumio[2781]: info: Feb 24 00:22:24 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:22:24 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:22:24 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:22:24 volumio volumio[2781]: info: sendMpdCommand status took 23 milliseconds Feb 24 00:22:24 volumio volumio[2781]: info: sendMpdCommand status took 22 milliseconds Feb 24 00:22:24 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 4 milliseconds Feb 24 00:22:24 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:22:24 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:22:24 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:22:24 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:22:24 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:22:24 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:22:24 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:22:24 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:22:24 volumio volumio[2781]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"dance.mp3","artist":"(#1 - 5863/32000) Dance Wave!","album":null,"uri":"https://dancewave.online:443/dance.mp3","trackType":"mp3"} Feb 24 00:22:24 volumio volumio[2781]: verbose: CURRENT POSITION 0 Feb 24 00:22:24 volumio volumio[2781]: info: CoreStateMachine::syncState stateService play Feb 24 00:22:24 volumio volumio[2781]: info: CoreStateMachine::syncState currentStatus stop Feb 24 00:22:24 volumio volumio[2781]: info: ------------------------------ 35ms Feb 24 00:22:24 volumio volumio[2781]: info: Feb 24 00:22:24 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:22:24 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:22:24 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:22:25 volumio volumio[2781]: info: Feb 24 00:22:25 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:22:25 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:22:25 volumio volumio[2781]: info: Feb 24 00:22:25 volumio volumio[2781]: ---------------------------- MPD announces system playlist update Feb 24 00:22:25 volumio volumio[2781]: info: Ignoring MPD Status Update Feb 24 00:22:25 volumio volumio[2781]: info: Feb 24 00:22:25 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:22:25 volumio volumio[2781]: info: Feb 24 00:22:25 volumio volumio[2781]: ---------------------------- MPD announces system playlist update Feb 24 00:22:25 volumio volumio[2781]: info: Ignoring MPD Status Update Feb 24 00:22:25 volumio volumio[2781]: info: Feb 24 00:22:25 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:22:25 volumio volumio[2781]: info: sendMpdCommand status took 17 milliseconds Feb 24 00:22:25 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 14 milliseconds Feb 24 00:22:25 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:22:25 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 14 milliseconds Feb 24 00:22:25 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:22:25 volumio volumio[2781]: info: sendMpdCommand status took 9 milliseconds Feb 24 00:22:25 volumio volumio[2781]: info: sendMpdCommand status took 7 milliseconds Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:22:25 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:22:25 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:22:25 volumio volumio[2781]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"dance.mp3","artist":"(#1 - 5863/32000) Dance Wave!","album":null,"uri":"https://dancewave.online:443/dance.mp3","trackType":"mp3"} Feb 24 00:22:25 volumio volumio[2781]: verbose: CURRENT POSITION 0 Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::syncState stateService play Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::syncState currentStatus play Feb 24 00:22:25 volumio volumio[2781]: info: Received an update from plugin. extracting info from payload Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:25 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:22:25 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:22:25 volumio volumio[2781]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Tracklist: https://dancewave.online","artist":"Dance Wave!","album":null,"uri":"https://dancewave.online:443/dance.mp3","trackType":"mp3"} Feb 24 00:22:25 volumio volumio[2781]: verbose: CURRENT POSITION 0 Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::syncState stateService play Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::syncState currentStatus play Feb 24 00:22:25 volumio volumio[2781]: info: Received an update from plugin. extracting info from payload Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:25 volumio volumio[2781]: info: ------------------------------ 75ms Feb 24 00:22:25 volumio volumio[2781]: info: ------------------------------ 82ms Feb 24 00:22:25 volumio volumio[2781]: info: Feb 24 00:22:25 volumio volumio[2781]: ---------------------------- MPD announces system playlist update Feb 24 00:22:25 volumio volumio[2781]: info: Ignoring MPD Status Update Feb 24 00:22:25 volumio volumio[2781]: info: Feb 24 00:22:25 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:22:25 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:22:25 volumio volumio[2781]: info: Feb 24 00:22:25 volumio volumio[2781]: ---------------------------- MPD announces system playlist update Feb 24 00:22:25 volumio volumio[2781]: info: Ignoring MPD Status Update Feb 24 00:22:25 volumio volumio[2781]: info: Feb 24 00:22:25 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:22:25 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:22:25 volumio volumio[2781]: info: ------------------------------ 54ms Feb 24 00:22:25 volumio volumio[2781]: info: sendMpdCommand status took 51 milliseconds Feb 24 00:22:25 volumio volumio[2781]: info: ------------------------------ 54ms Feb 24 00:22:25 volumio volumio[2781]: info: sendMpdCommand status took 51 milliseconds Feb 24 00:22:25 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 50 milliseconds Feb 24 00:22:25 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 47 milliseconds Feb 24 00:22:25 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 48 milliseconds Feb 24 00:22:25 volumio volumio[2781]: info: ------------------------------ 9ms Feb 24 00:22:25 volumio volumio[2781]: info: sendMpdCommand status took 8 milliseconds Feb 24 00:22:25 volumio volumio[2781]: info: ------------------------------ 7ms Feb 24 00:22:25 volumio volumio[2781]: info: sendMpdCommand status took 7 milliseconds Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:22:25 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:22:25 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:22:25 volumio volumio[2781]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Tracklist: https://dancewave.online","artist":"Dance Wave!","album":null,"uri":"https://dancewave.online:443/dance.mp3","trackType":"mp3"} Feb 24 00:22:25 volumio volumio[2781]: verbose: CURRENT POSITION 0 Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::syncState stateService play Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::syncState currentStatus play Feb 24 00:22:25 volumio volumio[2781]: info: Received an update from plugin. extracting info from payload Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:25 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:22:25 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:22:25 volumio volumio[2781]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Tracklist: https://dancewave.online","artist":"Dance Wave!","album":null,"uri":"https://dancewave.online:443/dance.mp3","trackType":"mp3"} Feb 24 00:22:25 volumio volumio[2781]: verbose: CURRENT POSITION 0 Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::syncState stateService play Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::syncState currentStatus play Feb 24 00:22:25 volumio volumio[2781]: info: Received an update from plugin. extracting info from payload Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:25 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:22:25 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:22:25 volumio volumio[2781]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Tracklist: https://dancewave.online","artist":"Dance Wave!","album":null,"uri":"https://dancewave.online:443/dance.mp3","trackType":"mp3"} Feb 24 00:22:25 volumio volumio[2781]: verbose: CURRENT POSITION 0 Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::syncState stateService play Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::syncState currentStatus play Feb 24 00:22:25 volumio volumio[2781]: info: Received an update from plugin. extracting info from payload Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:25 volumio volumio[2781]: info: ------------------------------ 106ms Feb 24 00:22:25 volumio volumio[2781]: info: ------------------------------ 97ms Feb 24 00:22:25 volumio volumio[2781]: info: ------------------------------ 98ms Feb 24 00:22:25 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 62 milliseconds Feb 24 00:22:25 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 61 milliseconds Feb 24 00:22:25 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 61 milliseconds Feb 24 00:22:25 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 61 milliseconds Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:22:25 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:22:25 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:22:25 volumio volumio[2781]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Tracklist: https://dancewave.online","artist":"Dance Wave!","album":null,"uri":"https://dancewave.online:443/dance.mp3","trackType":"mp3"} Feb 24 00:22:25 volumio volumio[2781]: verbose: CURRENT POSITION 0 Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::syncState stateService play Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::syncState currentStatus play Feb 24 00:22:25 volumio volumio[2781]: info: Received an update from plugin. extracting info from payload Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:25 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:22:25 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:22:25 volumio volumio[2781]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Tracklist: https://dancewave.online","artist":"Dance Wave!","album":null,"uri":"https://dancewave.online:443/dance.mp3","trackType":"mp3"} Feb 24 00:22:25 volumio volumio[2781]: verbose: CURRENT POSITION 0 Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::syncState stateService play Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::syncState currentStatus play Feb 24 00:22:25 volumio volumio[2781]: info: Received an update from plugin. extracting info from payload Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:25 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:22:25 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:22:25 volumio volumio[2781]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Tracklist: https://dancewave.online","artist":"Dance Wave!","album":null,"uri":"https://dancewave.online:443/dance.mp3","trackType":"mp3"} Feb 24 00:22:25 volumio volumio[2781]: verbose: CURRENT POSITION 0 Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::syncState stateService play Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::syncState currentStatus play Feb 24 00:22:25 volumio volumio[2781]: info: Received an update from plugin. extracting info from payload Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:25 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:22:25 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:22:25 volumio volumio[2781]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Tracklist: https://dancewave.online","artist":"Dance Wave!","album":null,"uri":"https://dancewave.online:443/dance.mp3","trackType":"mp3"} Feb 24 00:22:25 volumio volumio[2781]: verbose: CURRENT POSITION 0 Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::syncState stateService play Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::syncState currentStatus play Feb 24 00:22:25 volumio volumio[2781]: info: Received an update from plugin. extracting info from payload Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:25 volumio volumio[2781]: info: ------------------------------ 168ms Feb 24 00:22:25 volumio volumio[2781]: info: ------------------------------ 168ms Feb 24 00:22:25 volumio volumio[2781]: info: ------------------------------ 123ms Feb 24 00:22:25 volumio volumio[2781]: info: ------------------------------ 122ms Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::volumioStop Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::stop Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::stPlaybackTimer Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::updateTrackBlock Feb 24 00:22:25 volumio volumio[2781]: info: CorePlayQueue::getTrackBlock Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::serviceStop Feb 24 00:22:25 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::serviceStop Feb 24 00:22:25 volumio volumio[2781]: info: [1771874545328] ControllerWebradio::stop Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand stop Feb 24 00:22:25 volumio volumio[2781]: info: sendMpdCommand stop took 12 milliseconds Feb 24 00:22:25 volumio volumio[2781]: info: Feb 24 00:22:25 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:22:25 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:22:25 volumio volumio[2781]: info: Feb 24 00:22:25 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:22:25 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:22:25 volumio volumio[2781]: info: Feb 24 00:22:25 volumio volumio[2781]: ---------------------------- MPD announces state update: player Feb 24 00:22:25 volumio volumio[2781]: info: ControllerMpd::getState Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand status Feb 24 00:22:25 volumio volumio[2781]: info: sendMpdCommand status took 7 milliseconds Feb 24 00:22:25 volumio volumio[2781]: info: sendMpdCommand status took 5 milliseconds Feb 24 00:22:25 volumio volumio[2781]: info: sendMpdCommand status took 3 milliseconds Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::parseState Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 00:22:25 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 24 00:22:25 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 4 milliseconds Feb 24 00:22:25 volumio volumio[2781]: info: sendMpdCommand playlistinfo took 4 milliseconds Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:22:25 volumio volumio[2781]: verbose: ControllerMpd::parseTrackInfo Feb 24 00:22:25 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:25 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:22:25 volumio volumio[2781]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Feb 24 00:22:25 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:25 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:22:25 volumio volumio[2781]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Feb 24 00:22:25 volumio volumio[2781]: info: ControllerMpd::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::servicePushState Feb 24 00:22:25 volumio volumio[2781]: info: CoreStateMachine::pushState Feb 24 00:22:25 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:22:25 volumio volumio[2781]: info: CoreCommandRouter::volumioPushState Feb 24 00:22:25 volumio volumio[2781]: info: CorePlayQueue::getTrack 0 Feb 24 00:22:25 volumio volumio[2781]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Feb 24 00:22:25 volumio volumio[2781]: info: ------------------------------ 32ms Feb 24 00:22:25 volumio volumio[2781]: info: ------------------------------ 31ms Feb 24 00:22:25 volumio volumio[2781]: info: ------------------------------ 29ms Feb 24 00:22:26 volumio volumio[2781]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 24 00:22:26 volumio volumio[2781]: TypeError: Cannot read properties of null (reading 'slice') Feb 24 00:22:26 volumio volumio[2781]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41) Feb 24 00:22:26 volumio volumio[2781]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7) Feb 24 00:22:26 volumio volumio[2781]: at Object.onceWrapper (node:events:629:26) Feb 24 00:22:26 volumio volumio[2781]: at ClientRequest.emit (node:events:514:28) Feb 24 00:22:26 volumio volumio[2781]: at HTTPParser.parserOnIncomingClient [as onIncoming] (node:_http_client:693:27) Feb 24 00:22:26 volumio volumio[2781]: at HTTPParser.parserOnHeadersComplete (node:_http_common:119:17) Feb 24 00:22:26 volumio volumio[2781]: at TLSSocket.socketOnData (node:_http_client:535:22) Feb 24 00:22:26 volumio volumio[2781]: at TLSSocket.emit (node:events:514:28) Feb 24 00:22:26 volumio volumio[2781]: at addChunk (node:internal/streams/readable:343:12) Feb 24 00:22:26 volumio volumio[2781]: at readableAddChunk (node:internal/streams/readable:316:9) Feb 24 00:22:26 volumio volumio[2781]: at Readable.push (node:internal/streams/readable:253:10) Feb 24 00:22:26 volumio volumio[2781]: at TLSWrap.onStreamRead (node:internal/stream_base_commons:190:23) Feb 24 00:22:26 volumio volumio[2781]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 24 00:22:27 volumio sudo[7604]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-24 00:21' Feb 24 00:22:27 volumio sudo[7604]: 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="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"