-- Logs begin at Thu 2019-02-14 15:11:58 +05, end at Mon 2025-05-12 21:04:29 +05. -- May 12 21:03:05 volumio volumio[1042]: info: May 12 21:03:05 volumio volumio[1042]: ---------------------------- MPD announces state update: player May 12 21:03:05 volumio volumio[1042]: info: ControllerMpd::getState May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand status May 12 21:03:05 volumio volumio[1042]: info: May 12 21:03:05 volumio volumio[1042]: ---------------------------- MPD announces state update: player May 12 21:03:05 volumio systemd-timedated[1419]: Changed local time to Mon May 12 21:03:05 2025 May 12 21:03:05 volumio volumio[1042]: info: ControllerMpd::getState May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand status May 12 21:03:05 volumio volumio[1042]: info: sendMpdCommand status took 518037661 milliseconds May 12 21:03:05 volumio volumio[1042]: info: sendMpdCommand playlistinfo took 518037660 milliseconds May 12 21:03:05 volumio volumio-time-update[566]: volumio-time-update-util: System time updated successfully. May 12 21:03:05 volumio sudo[1417]: pam_unix(sudo:session): session closed for user root May 12 21:03:05 volumio volumio[1042]: info: sendMpdCommand playlistinfo took 518037659 milliseconds May 12 21:03:05 volumio volumio[1042]: info: sendMpdCommand status took 518037657 milliseconds May 12 21:03:05 volumio volumio[1042]: info: sendMpdCommand status took 518037654 milliseconds May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::parseState May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::parseTrackInfo May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::parseTrackInfo May 12 21:03:05 volumio systemd[1]: Starting Daily apt download activities... May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::parseTrackInfo May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::parseState May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::parseState May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 21:03:05 volumio systemd[1]: Started Volumio Time Update Utility. May 12 21:03:05 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:05 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:05 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:05 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:05 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:05 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:05 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:05 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:05 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:05 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:05 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:05 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:05 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:05 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:05 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:05 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:05 volumio systemd[1]: Reached target Multi-User System. May 12 21:03:05 volumio volumio[1042]: info: ------------------------------ 518037733ms May 12 21:03:05 volumio volumio[1042]: info: ------------------------------ 518037732ms May 12 21:03:05 volumio volumio[1042]: info: ------------------------------ 518037730ms May 12 21:03:05 volumio systemd[1]: Reached target Graphical Interface. May 12 21:03:05 volumio volumio[1042]: info: ------------------------------ 518037730ms May 12 21:03:05 volumio volumio[1042]: info: sendMpdCommand status took 22 milliseconds May 12 21:03:05 volumio volumio[1042]: info: sendMpdCommand playlistinfo took 18 milliseconds May 12 21:03:05 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... May 12 21:03:05 volumio volumio[1042]: info: sendMpdCommand playlistinfo took 10 milliseconds May 12 21:03:05 volumio volumio[1042]: info: sendMpdCommand playlistinfo took 11 milliseconds May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::parseState May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::parseTrackInfo May 12 21:03:05 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:05 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:05 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:05 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:05 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:05 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:05 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:05 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:05 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:05 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:05 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:05 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:05 volumio volumio[1042]: info: ------------------------------ 518037700ms May 12 21:03:05 volumio volumio[1042]: info: ------------------------------ 518037689ms May 12 21:03:05 volumio volumio[1042]: info: ------------------------------ 518037686ms May 12 21:03:05 volumio volumio[1042]: info: sendMpdCommand playlistinfo took 10 milliseconds May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::parseTrackInfo May 12 21:03:05 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:05 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:05 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:05 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:05 volumio volumio[1042]: info: ------------------------------ 518037690ms May 12 21:03:05 volumio volumio[1042]: info: May 12 21:03:05 volumio volumio[1042]: ---------------------------- MPD announces system playlist update May 12 21:03:05 volumio volumio[1042]: info: Ignoring MPD Status Update May 12 21:03:05 volumio volumio[1042]: info: May 12 21:03:05 volumio volumio[1042]: ---------------------------- MPD announces state update: player May 12 21:03:05 volumio volumio[1042]: info: ControllerMpd::getState May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand status May 12 21:03:05 volumio volumio[1042]: info: May 12 21:03:05 volumio volumio[1042]: ---------------------------- MPD announces system playlist update May 12 21:03:05 volumio volumio[1042]: info: Ignoring MPD Status Update May 12 21:03:05 volumio volumio[1042]: info: May 12 21:03:05 volumio volumio[1042]: ---------------------------- MPD announces state update: player May 12 21:03:05 volumio volumio[1042]: info: ControllerMpd::getState May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand status May 12 21:03:05 volumio volumio[1042]: info: May 12 21:03:05 volumio volumio[1042]: ---------------------------- MPD announces system playlist update May 12 21:03:05 volumio volumio[1042]: info: Ignoring MPD Status Update May 12 21:03:05 volumio volumio[1042]: info: May 12 21:03:05 volumio volumio[1042]: ---------------------------- MPD announces state update: player May 12 21:03:05 volumio volumio[1042]: info: ControllerMpd::getState May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand status May 12 21:03:05 volumio volumio[1042]: info: May 12 21:03:05 volumio volumio[1042]: ---------------------------- MPD announces system playlist update May 12 21:03:05 volumio volumio[1042]: info: Ignoring MPD Status Update May 12 21:03:05 volumio volumio[1042]: info: May 12 21:03:05 volumio volumio[1042]: ---------------------------- MPD announces state update: player May 12 21:03:05 volumio volumio[1042]: info: ControllerMpd::getState May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand status May 12 21:03:05 volumio volumio[1042]: info: May 12 21:03:05 volumio volumio[1042]: ---------------------------- MPD announces system playlist update May 12 21:03:05 volumio volumio[1042]: info: Ignoring MPD Status Update May 12 21:03:05 volumio volumio[1042]: info: May 12 21:03:05 volumio volumio[1042]: ---------------------------- MPD announces state update: player May 12 21:03:05 volumio volumio[1042]: info: ControllerMpd::getState May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand status May 12 21:03:05 volumio volumio[1042]: info: ------------------------------ 20ms May 12 21:03:05 volumio volumio[1042]: info: sendMpdCommand status took 18 milliseconds May 12 21:03:05 volumio volumio[1042]: info: ------------------------------ 17ms May 12 21:03:05 volumio volumio[1042]: info: sendMpdCommand status took 16 milliseconds May 12 21:03:05 volumio volumio[1042]: info: ------------------------------ 16ms May 12 21:03:05 volumio volumio[1042]: info: sendMpdCommand status took 14 milliseconds May 12 21:03:05 volumio volumio[1042]: info: ------------------------------ 14ms May 12 21:03:05 volumio volumio[1042]: info: sendMpdCommand status took 11 milliseconds May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::parseState May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::parseState May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::parseState May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::parseState May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 21:03:05 volumio volumio[1042]: info: May 12 21:03:05 volumio volumio[1042]: ---------------------------- MPD announces system playlist update May 12 21:03:05 volumio volumio[1042]: info: Ignoring MPD Status Update May 12 21:03:05 volumio volumio[1042]: info: May 12 21:03:05 volumio volumio[1042]: ---------------------------- MPD announces state update: player May 12 21:03:05 volumio volumio[1042]: info: ControllerMpd::getState May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand status May 12 21:03:05 volumio volumio[1042]: info: May 12 21:03:05 volumio volumio[1042]: ---------------------------- MPD announces system playlist update May 12 21:03:05 volumio volumio[1042]: info: Ignoring MPD Status Update May 12 21:03:05 volumio volumio[1042]: info: May 12 21:03:05 volumio volumio[1042]: ---------------------------- MPD announces state update: player May 12 21:03:05 volumio volumio[1042]: info: ControllerMpd::getState May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand status May 12 21:03:05 volumio volumio[1042]: info: May 12 21:03:05 volumio volumio[1042]: ---------------------------- MPD announces system playlist update May 12 21:03:05 volumio volumio[1042]: info: Ignoring MPD Status Update May 12 21:03:05 volumio volumio[1042]: info: May 12 21:03:05 volumio volumio[1042]: ---------------------------- MPD announces state update: player May 12 21:03:05 volumio volumio[1042]: info: ControllerMpd::getState May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand status May 12 21:03:05 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. May 12 21:03:05 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. May 12 21:03:05 volumio volumio[1042]: info: ------------------------------ 25ms May 12 21:03:05 volumio volumio[1042]: info: sendMpdCommand status took 20 milliseconds May 12 21:03:05 volumio volumio[1042]: info: sendMpdCommand playlistinfo took 16 milliseconds May 12 21:03:05 volumio volumio[1042]: info: sendMpdCommand playlistinfo took 17 milliseconds May 12 21:03:05 volumio volumio[1042]: info: sendMpdCommand playlistinfo took 16 milliseconds May 12 21:03:05 volumio volumio[1042]: info: sendMpdCommand playlistinfo took 15 milliseconds May 12 21:03:05 volumio volumio[1042]: info: ------------------------------ 14ms May 12 21:03:05 volumio volumio[1042]: info: sendMpdCommand status took 13 milliseconds May 12 21:03:05 volumio volumio[1042]: info: ------------------------------ 13ms May 12 21:03:05 volumio volumio[1042]: info: sendMpdCommand status took 12 milliseconds May 12 21:03:05 volumio volumio[1042]: info: ------------------------------ 11ms May 12 21:03:05 volumio volumio[1042]: info: sendMpdCommand status took 10 milliseconds May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::parseState May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::parseTrackInfo May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::parseTrackInfo May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::parseTrackInfo May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::parseTrackInfo May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::parseState May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::parseState May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::parseState May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 21:03:05 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:05 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:05 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:05 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:05 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:05 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:05 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:05 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:05 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:05 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:05 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:05 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:05 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:05 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:05 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:05 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:05 volumio volumio[1042]: info: ------------------------------ 51ms May 12 21:03:05 volumio volumio[1042]: info: ------------------------------ 47ms May 12 21:03:05 volumio volumio[1042]: info: ------------------------------ 44ms May 12 21:03:05 volumio volumio[1042]: info: ------------------------------ 41ms May 12 21:03:05 volumio volumio[1042]: info: sendMpdCommand playlistinfo took 28 milliseconds May 12 21:03:05 volumio volumio[1042]: info: sendMpdCommand playlistinfo took 26 milliseconds May 12 21:03:05 volumio volumio[1042]: info: sendMpdCommand playlistinfo took 26 milliseconds May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::parseTrackInfo May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::parseTrackInfo May 12 21:03:05 volumio volumio[1042]: verbose: ControllerMpd::parseTrackInfo May 12 21:03:05 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:05 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:05 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:05 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:05 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:05 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:05 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:05 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:05 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:05 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:05 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:05 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:05 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:05 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:05 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:05 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:05 volumio volumio[1042]: info: ------------------------------ 62ms May 12 21:03:05 volumio volumio[1042]: info: ------------------------------ 53ms May 12 21:03:05 volumio volumio[1042]: info: ------------------------------ 52ms May 12 21:03:05 volumio volumio[1042]: info: ------------------------------ 50ms May 12 21:03:05 volumio volumio[1042]: info: Discovery: A device disappeared from network May 12 21:03:05 volumio volumio[1042]: info: Discovery: Device volumio disappeared from network May 12 21:03:05 volumio volumio[1042]: info: Discovery: A device disappeared from network May 12 21:03:05 volumio volumio[1042]: info: Discovery: adding 4a6569df-31a7-489d-b819-c4eb848648b0 May 12 21:03:05 volumio volumio[1042]: info: Discovery: Found device Volumio May 12 21:03:05 volumio volumio[1042]: info: CoreCommandRouter::volumioGetState May 12 21:03:05 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:05 volumio volumio[1042]: info: Discovery: this is already registered, 4a6569df-31a7-489d-b819-c4eb848648b0 May 12 21:03:05 volumio volumio[1042]: info: Discovery: Found device Volumio May 12 21:03:05 volumio volumio[1042]: info: CoreCommandRouter::volumioGetState May 12 21:03:05 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:05 volumio volumio[1042]: info: Updating MyVolumio device info May 12 21:03:05 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 21:03:05 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 21:03:05 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 21:03:05 volumio volumio[1042]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} May 12 21:03:06 volumio volumio[1042]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} May 12 21:03:07 volumio systemd[1]: apt-daily.service: Succeeded. May 12 21:03:07 volumio systemd[1]: Started Daily apt download activities. May 12 21:03:07 volumio systemd[1]: Starting Daily apt upgrade and clean activities... May 12 21:03:07 volumio volumio[1287]: .....................................................................................................................................................++++ May 12 21:03:07 volumio volumio[1287]: e is 65537 (0x010001) May 12 21:03:07 volumio volumio[1287]: writing RSA key May 12 21:03:08 volumio systemd[1]: apt-daily-upgrade.service: Succeeded. May 12 21:03:08 volumio systemd[1]: Started Daily apt upgrade and clean activities. May 12 21:03:08 volumio systemd[1]: Startup finished in 11.857s (kernel) + 1min 6.435s (userspace) = 1min 18.292s. May 12 21:03:10 volumio volumio[1042]: info: MYVOLUMIO: Adding device May 12 21:03:10 volumio volumio[1042]: info: MYVOLUMIO: Evaluating Server May 12 21:03:10 volumio volumio[1042]: info: CoreCommandRouter::getUIConfigOnPlugin May 12 21:03:10 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 12 21:03:10 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 21:03:10 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 12 21:03:10 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 12 21:03:10 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 12 21:03:10 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 12 21:03:10 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 12 21:03:10 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 12 21:03:10 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 12 21:03:10 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 12 21:03:10 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 12 21:03:10 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 12 21:03:10 volumio volumio[1042]: info: Setting Geolocation for MyVolumio to eu4 May 12 21:03:10 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 21:03:10 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 21:03:10 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 21:03:11 volumio volumio[1042]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} May 12 21:03:11 volumio volumio[1042]: info: Updating MyVolumio device info May 12 21:03:11 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 21:03:11 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 21:03:11 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 21:03:12 volumio volumio[1042]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} May 12 21:03:14 volumio ntpd[765]: Soliciting pool server 193.111.10.75 May 12 21:03:14 volumio ntpd[765]: Soliciting pool server 62.122.137.35 May 12 21:03:15 volumio ntpd[765]: Soliciting pool server 62.122.137.131 May 12 21:03:15 volumio ntpd[765]: Soliciting pool server 62.122.137.131 May 12 21:03:15 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 12 21:03:15 volumio volumio[1042]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 40 May 12 21:03:15 volumio volumio[1042]: info: CoreCommandRouter::volumioGetState May 12 21:03:15 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:16 volumio ntpd[765]: Soliciting pool server 2a0a:280:35f1:1337::119a May 12 21:03:17 volumio volumio[1042]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions May 12 21:03:17 volumio volumio[1042]: info: Preparing to save Alsa Options, stopping services first May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::volumioGetState May 12 21:03:17 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::volumioPause May 12 21:03:17 volumio volumio[1042]: info: CoreStateMachine::pause May 12 21:03:17 volumio volumio[1042]: info: CoreStateMachine::stPlaybackTimer May 12 21:03:17 volumio volumio[1042]: info: CoreStateMachine::servicePause May 12 21:03:17 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::servicePause May 12 21:03:17 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand pause May 12 21:03:17 volumio volumio[1042]: info: Saving Audio Output to: {"output_device":{"value":"0","label":"HDMI Out"},"i2s":false,"i2sid":{"value":"adafruit-max98357","label":"Adafruit MAX98357"}} May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 12 21:03:17 volumio volumio[1042]: info: Enabling PI HDMI Output May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 12 21:03:17 volumio volumio[1042]: info: Found match in Cards Database: setting mixer PCM for card HDMI Out May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 12 21:03:17 volumio volumio[1042]: info: Updating Volume Controller Parameters: Device: 0 Name: HDMI Out Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 12 21:03:17 volumio volumio[1042]: info: Disabling external Volume Control May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::getUIConfigOnPlugin May 12 21:03:17 volumio volumio[1042]: info: Preparing to generate the ALSA configuration file May 12 21:03:17 volumio volumio[1042]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 12 21:03:17 volumio volumio[1042]: info: Reading ALSA contributions from plugins. May 12 21:03:17 volumio volumio[1042]: info: May 12 21:03:17 volumio volumio[1042]: ---------------------------- MPD announces state update: player May 12 21:03:17 volumio volumio[1042]: info: sendMpdCommand pause took 165 milliseconds May 12 21:03:17 volumio volumio[1042]: info: ControllerMpd::getState May 12 21:03:17 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand status May 12 21:03:17 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:17 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:17 volumio volumio[1042]: verbose: STATE SERVICE {"status":"pause","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is2-ssl.mzstatic.com/image/thumb/Music113/v4/f1/91/ef/f191effe-4cf2-932b-f2cf-a724454d2d49/source/600x600bb.jpg","name":"Oasis - Don't Look Back In Anger","title":"Don't Look Back In Anger","artist":"90s90s Hits","album":"","streaming":true,"disableUiControls":true,"duration":"282","seek":518052628,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} May 12 21:03:17 volumio volumio[1042]: verbose: CURRENT POSITION 0 May 12 21:03:17 volumio volumio[1042]: info: CoreStateMachine::syncState stateService pause May 12 21:03:17 volumio volumio[1042]: info: CoreStateMachine::syncState currentStatus pause May 12 21:03:17 volumio volumio[1042]: info: CoreStateMachine::pushState May 12 21:03:17 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::volumioPushState May 12 21:03:17 volumio volumio[1042]: info: CoreStateMachine::stPlaybackTimer May 12 21:03:17 volumio volumio[1042]: info: May 12 21:03:17 volumio volumio[1042]: ---------------------------- MPD announces state update: player May 12 21:03:17 volumio volumio[1042]: info: ControllerMpd::getState May 12 21:03:17 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand status May 12 21:03:17 volumio volumio[1042]: info: May 12 21:03:17 volumio volumio[1042]: ---------------------------- MPD announces state update: player May 12 21:03:17 volumio volumio[1042]: info: ControllerMpd::getState May 12 21:03:17 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand status May 12 21:03:17 volumio volumio[1042]: info: May 12 21:03:17 volumio volumio[1042]: ---------------------------- MPD announces state update: player May 12 21:03:17 volumio volumio[1042]: info: ControllerMpd::getState May 12 21:03:17 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand status May 12 21:03:17 volumio volumio[1042]: info: Raspberry PI HDMI Output Enabled May 12 21:03:17 volumio volumio[1042]: info: sendMpdCommand status took 47 milliseconds May 12 21:03:17 volumio volumio[1042]: info: sendMpdCommand status took 35 milliseconds May 12 21:03:17 volumio volumio[1042]: info: sendMpdCommand status took 34 milliseconds May 12 21:03:17 volumio volumio[1042]: info: sendMpdCommand status took 33 milliseconds May 12 21:03:17 volumio volumio[1042]: verbose: ControllerMpd::parseState May 12 21:03:17 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 21:03:17 volumio volumio[1042]: verbose: ControllerMpd::parseState May 12 21:03:17 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 21:03:17 volumio volumio[1042]: verbose: ControllerMpd::parseState May 12 21:03:17 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 21:03:17 volumio volumio[1042]: verbose: ControllerMpd::parseState May 12 21:03:17 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 21:03:17 volumio volumio[1042]: SPOTIFY: RECEIVED VOLUMIO VOLUME 54 May 12 21:03:17 volumio sudo[1675]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl store May 12 21:03:17 volumio sudo[1675]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 21:03:17 volumio volumio[1042]: info: sendMpdCommand playlistinfo took 13 milliseconds May 12 21:03:17 volumio volumio[1042]: info: sendMpdCommand playlistinfo took 12 milliseconds May 12 21:03:17 volumio volumio[1042]: info: sendMpdCommand playlistinfo took 13 milliseconds May 12 21:03:17 volumio volumio[1042]: info: sendMpdCommand playlistinfo took 12 milliseconds May 12 21:03:17 volumio volumio[1042]: verbose: ControllerMpd::parseTrackInfo May 12 21:03:17 volumio volumio[1042]: verbose: ControllerMpd::parseTrackInfo May 12 21:03:17 volumio volumio[1042]: verbose: ControllerMpd::parseTrackInfo May 12 21:03:17 volumio volumio[1042]: verbose: ControllerMpd::parseTrackInfo May 12 21:03:17 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:17 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:17 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:17 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:17 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:17 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:17 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:17 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:17 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:17 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:17 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:17 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:17 volumio volumio[1042]: info: ------------------------------ 70ms May 12 21:03:17 volumio volumio[1042]: info: ------------------------------ 57ms May 12 21:03:17 volumio volumio[1042]: info: ------------------------------ 56ms May 12 21:03:17 volumio volumio[1042]: info: ------------------------------ 55ms May 12 21:03:17 volumio volumio[1042]: info: VolumeController:: Volume=86 Mute =false May 12 21:03:17 volumio volumio[1042]: info: CoreStateMachine::pushState May 12 21:03:17 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::volumioPushState May 12 21:03:17 volumio sudo[1675]: pam_unix(sudo:session): session closed for user root May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 12 21:03:17 volumio volumio[1042]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 May 12 21:03:17 volumio volumio[1042]: SPOTIFY: SPOTIFY VOLUME 54 May 12 21:03:17 volumio volumio[1042]: SPOTIFY: VOLUMIO VOLUME 86 May 12 21:03:17 volumio volumio[1042]: SPOTIFY: DELTA VOLUME ENOUGH: true May 12 21:03:17 volumio volumio[1042]: info: Setting Spotify Volume from Volumio: 86 May 12 21:03:17 volumio volumio[1042]: info: Alsa Settings successfully stored May 12 21:03:17 volumio volumio[1042]: info: Asound.conf file written May 12 21:03:17 volumio sudo[1688]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf May 12 21:03:17 volumio sudo[1688]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 21:03:17 volumio sudo[1688]: pam_unix(sudo:session): session closed for user root May 12 21:03:17 volumio volumio[1042]: info: Output device has changed, restarting MPD May 12 21:03:17 volumio sudo[1693]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 12 21:03:17 volumio volumio[1042]: info: Output device has changed, restarting Shairport Sync May 12 21:03:17 volumio sudo[1693]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 21:03:17 volumio sudo[1693]: pam_unix(sudo:session): session closed for user root May 12 21:03:17 volumio sudo[1695]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 12 21:03:17 volumio sudo[1695]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 21:03:17 volumio systemd[1]: Stopping Music Player Daemon... May 12 21:03:17 volumio volumio[1042]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 12 21:03:17 volumio volumio[1042]: info: Output device has changed, restarting MPD May 12 21:03:17 volumio systemd[1]: mpd.service: Succeeded. May 12 21:03:17 volumio systemd[1]: Stopped Music Player Daemon. May 12 21:03:17 volumio sudo[1702]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 12 21:03:17 volumio sudo[1702]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 21:03:17 volumio volumio[1042]: info: Output device has changed, restarting Shairport Sync May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 21:03:17 volumio sudo[1702]: pam_unix(sudo:session): session closed for user root May 12 21:03:17 volumio systemd[1]: Starting Music Player Daemon... May 12 21:03:17 volumio sudo[1705]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 12 21:03:17 volumio sudo[1705]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 21:03:17 volumio volumio[1042]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 12 21:03:17 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM May 12 21:03:17 volumio systemd[1]: mpd.service: Succeeded. May 12 21:03:17 volumio systemd[1]: Stopped Music Player Daemon. May 12 21:03:17 volumio volumio[1042]: info: MPD Permissions set May 12 21:03:17 volumio volumio[1042]: info: MPD Permissions set May 12 21:03:17 volumio systemd[1]: Starting Music Player Daemon... May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:03:17 volumio volumio[1042]: info: Starting Shairport Sync May 12 21:03:17 volumio volumio[1042]: info: Starting Shairport Sync May 12 21:03:17 volumio sudo[1711]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 12 21:03:17 volumio sudo[1711]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 21:03:17 volumio sudo[1711]: pam_unix(sudo:session): session closed for user root May 12 21:03:17 volumio sudo[1721]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 12 21:03:18 volumio sudo[1721]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 21:03:18 volumio sudo[1725]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 12 21:03:18 volumio sudo[1725]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 21:03:18 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 12 21:03:18 volumio systemd[1]: shairport-sync.service: Succeeded. May 12 21:03:18 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 12 21:03:18 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 12 21:03:18 volumio sudo[1725]: pam_unix(sudo:session): session closed for user root May 12 21:03:18 volumio sudo[1721]: pam_unix(sudo:session): session closed for user root May 12 21:03:18 volumio volumio[1042]: info: Shairport-Sync Started May 12 21:03:18 volumio volumio[1042]: info: Shairport-Sync Started May 12 21:03:18 volumio mpd[1724]: May 12 21:03 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 12 21:03:18 volumio systemd[1]: Started Music Player Daemon. May 12 21:03:18 volumio sudo[1695]: pam_unix(sudo:session): session closed for user root May 12 21:03:18 volumio sudo[1705]: pam_unix(sudo:session): session closed for user root May 12 21:03:18 volumio volumio[1042]: error: MPD error: The expression evaluated to a falsy value: May 12 21:03:18 volumio volumio[1042]: assert.ok(self.idling) May 12 21:03:18 volumio volumio[1042]: error: The expression evaluated to a falsy value: May 12 21:03:18 volumio volumio[1042]: assert.ok(self.idling) May 12 21:03:18 volumio volumio[1042]: error: updateQueue error: null May 12 21:03:19 volumio volumio[1042]: SPOTIFY: SETTING SPOTIFY VOLUME 86 May 12 21:03:19 volumio volumio[1042]: info: Sending Spotify command with payload to local API: /player/volume May 12 21:03:19 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 12 21:03:19 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 21:03:19 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 12 21:03:19 volumio volumio-remote-updater[556]: No test mode May 12 21:03:19 volumio volumio-remote-updater[556]: No alpha test mode May 12 21:03:19 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled May 12 21:03:19 volumio volumio[1042]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

NEW ADDITIONS

 

","title":"Update v3.807","updateavailable":true} May 12 21:03:19 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache May 12 21:03:20 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:03:20 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:03:20 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam May 12 21:03:20 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam May 12 21:03:20 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 12 21:03:20 volumio volumio[1042]: info: CoreCommandRouter::volumioGetBrowseSources May 12 21:03:20 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 12 21:03:21 volumio volumio[1042]: info: CoreCommandRouter::volumioRetrieveVolumeLevels May 12 21:03:21 volumio volumio[1042]: info: CoreStateMachine::getcurrentVolume May 12 21:03:21 volumio volumio[1042]: info: CoreCommandRouter::volumioRetrievevolume May 12 21:03:21 volumio volumio[1042]: info: VolumeController:: Volume=86 Mute =false May 12 21:03:21 volumio volumio[1042]: info: CoreStateMachine::pushState May 12 21:03:21 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:21 volumio volumio[1042]: info: CoreCommandRouter::volumioPushState May 12 21:03:21 volumio volumio[1042]: info: CoreStateMachine::updateTrackBlock May 12 21:03:21 volumio volumio[1042]: info: CorePlayQueue::getTrackBlock May 12 21:03:21 volumio volumio[1042]: info: CoreCommandRouter::volumioRetrievevolume May 12 21:03:21 volumio volumio[1042]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 May 12 21:03:21 volumio volumio[1042]: info: VolumeController:: Volume=86 Mute =false May 12 21:03:21 volumio volumio[1042]: info: CoreStateMachine::pushState May 12 21:03:21 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:21 volumio volumio[1042]: info: CoreCommandRouter::volumioPushState May 12 21:03:21 volumio volumio[1042]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 May 12 21:03:21 volumio volumio[1042]: error: Upnp client error: Error: This socket has been ended by the other party May 12 21:03:21 volumio volumio[1042]: error: MyVolumio Plugin failed to authenticate in a timely fashion May 12 21:03:21 volumio volumio[1042]: info: Completed starting MyVolumio Plugin May 12 21:03:21 volumio volumio[1042]: [Metrics] CommandRouter: 44s 708.00ms May 12 21:03:21 volumio volumio[1042]: info: CoreCommandRouter::volumiosetStartupVolume May 12 21:03:21 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:03:21 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 21:03:21 volumio volumio[1042]: info: CoreCommandRouter::Close All Modals sent May 12 21:03:21 volumio volumio[1042]: info: CoreCommandRouter::Close All Modals sent May 12 21:03:21 volumio volumio[1042]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 12 21:03:21 volumio volumio[1042]: info: FusionDsp - ---- read samplerate from file: 44100 May 12 21:03:21 volumio volumio[1042]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 12 21:03:21 volumio volumio[1042]: info: FusionDsp - Effects disabled May 12 21:03:21 volumio volumio[1042]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 12 21:03:21 volumio volumio[1042]: info: FusionDsp - ---- read samplerate from file: 44100 May 12 21:03:21 volumio volumio[1042]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 12 21:03:21 volumio volumio[1042]: info: FusionDsp - Effects disabled May 12 21:03:21 volumio volumio[1042]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 12 21:03:21 volumio volumio[1042]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 12 21:03:22 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable May 12 21:03:22 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 12 21:03:22 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect May 12 21:03:23 volumio ntpd[765]: receive: Unexpected origin timestamp 0xebcc9a4b.38915605 does not match aorg 0000000000.00000000 from server@193.111.10.75 xmt 0xebcc9a4b.a370368c May 12 21:03:23 volumio ntpd[765]: receive: Unexpected origin timestamp 0xebcc9a4b.388af6db does not match aorg 0000000000.00000000 from server@62.122.137.131 xmt 0xebcc9a4b.a3799450 May 12 21:03:27 volumio kernel: bcm2835_audio bcm2835_audio: failed to close VCHI service connection (status=-11) May 12 21:03:27 volumio volumio[1042]: info: CoreCommandRouter::volumioPlay May 12 21:03:27 volumio volumio[1042]: info: CoreStateMachine::play index undefined May 12 21:03:27 volumio volumio[1042]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 21:03:27 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:27 volumio volumio[1042]: info: CoreStateMachine::startPlaybackTimer May 12 21:03:27 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:27 volumio volumio[1042]: verbose: MPD COMMAND [object Object] May 12 21:03:27 volumio volumio[1042]: verbose: MPD COMMAND [object Object] May 12 21:03:29 volumio volumio[1042]: info: BOOT COMPLETED May 12 21:03:35 volumio systemd[1]: systemd-timedated.service: Succeeded. May 12 21:03:41 volumio volumio[1042]: info: CoreCommandRouter::volumioGetVisibleSources May 12 21:03:41 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 12 21:03:41 volumio volumio[1042]: info: CoreCommandRouter::volumioGetQueue May 12 21:03:41 volumio volumio[1042]: info: CoreStateMachine::getQueue May 12 21:03:41 volumio volumio[1042]: info: CorePlayQueue::getQueue May 12 21:03:46 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: 80s80s , handleBrowseUri May 12 21:03:46 volumio volumio[1042]: info: [1747065826422] [80s80s] handleBrowseUri curUri: 80s80s May 12 21:03:46 volumio volumio[1042]: info: Preload queue cleared May 12 21:03:47 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: 80s80s , handleBrowseUri May 12 21:03:47 volumio volumio[1042]: info: [1747065827590] [80s80s] handleBrowseUri curUri: 80s80s/nineties May 12 21:03:47 volumio volumio[1042]: info: [1747065827590] [80s80s] getRadioContent url: nineties May 12 21:03:47 volumio volumio[1042]: info: Preload queue cleared May 12 21:03:48 volumio volumio[1042]: info: Preload queue cleared May 12 21:03:48 volumio volumio[1042]: info: CoreCommandRouter::volumioReplaceandPlayItems May 12 21:03:48 volumio volumio[1042]: info: CoreStateMachine::ClearQueue May 12 21:03:48 volumio volumio[1042]: info: CoreStateMachine::stop May 12 21:03:48 volumio volumio[1042]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 21:03:48 volumio volumio[1042]: info: CoreStateMachine::updateTrackBlock May 12 21:03:48 volumio volumio[1042]: info: CorePlayQueue::getTrackBlock May 12 21:03:48 volumio volumio[1042]: info: CoreStateMachine::stPlaybackTimer May 12 21:03:48 volumio volumio[1042]: info: CoreStateMachine::pushState May 12 21:03:48 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:48 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 21:03:48 volumio volumio[1042]: info: CoreCommandRouter::volumioPushState May 12 21:03:48 volumio volumio[1042]: info: CoreStateMachine::serviceStop May 12 21:03:48 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:48 volumio volumio[1042]: info: CoreCommandRouter::serviceStop May 12 21:03:48 volumio volumio[1042]: info: ControllerMpd::stop May 12 21:03:48 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand stop May 12 21:03:48 volumio volumio[1042]: info: CorePlayQueue::clearPlayQueue May 12 21:03:48 volumio volumio[1042]: info: CorePlayQueue::saveQueue May 12 21:03:48 volumio volumio[1042]: info: CoreCommandRouter::volumioPushQueue May 12 21:03:48 volumio volumio[1042]: info: CoreStateMachine::addQueueItems May 12 21:03:48 volumio volumio[1042]: info: CorePlayQueue::addQueueItems May 12 21:03:48 volumio volumio[1042]: info: Preload queue cleared May 12 21:03:48 volumio volumio[1042]: info: Adding Item to queue: webnineties/0 May 12 21:03:48 volumio volumio[1042]: info: Exploding uri webnineties/0 in service 80s80s May 12 21:03:48 volumio volumio[1042]: info: [1747065828874] [80s80s] explodeUri: webnineties/0 May 12 21:03:48 volumio volumio[1042]: info: CoreCommandRouter::volumioPushQueue May 12 21:03:48 volumio volumio[1042]: info: CorePlayQueue::saveQueue May 12 21:03:48 volumio volumio[1042]: info: CoreStateMachine::updateTrackBlock May 12 21:03:48 volumio volumio[1042]: info: CorePlayQueue::getTrackBlock May 12 21:03:48 volumio volumio[1042]: info: CoreCommandRouter::volumioPlay May 12 21:03:48 volumio volumio[1042]: info: CoreStateMachine::play index 0 May 12 21:03:48 volumio volumio[1042]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 21:03:48 volumio volumio[1042]: info: CoreStateMachine::stop May 12 21:03:48 volumio volumio[1042]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 21:03:48 volumio volumio[1042]: info: CoreStateMachine::play index undefined May 12 21:03:48 volumio volumio[1042]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 21:03:48 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:48 volumio volumio[1042]: info: CoreStateMachine::startPlaybackTimer May 12 21:03:48 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:48 volumio volumio[1042]: info: [1747065828896] [80s80s] clearAddPlayTrack url: http://streams.90s90s.de/pop/mp3-192/volumio May 12 21:03:48 volumio volumio[1042]: info: [1747065828896] [80s80s] getContentOfUrl started with url http://iris-90s90s.loverad.io/flow.json?station=141&count=2 May 12 21:03:48 volumio volumio[1042]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 May 12 21:03:48 volumio volumio[1042]: info: sendMpdCommand stop took 33 milliseconds May 12 21:03:48 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:48 volumio volumio[1042]: info: CoreStateMachine::pushState May 12 21:03:48 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:48 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 21:03:48 volumio volumio[1042]: info: CoreCommandRouter::volumioPushState May 12 21:03:48 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:48 volumio volumio[1042]: verbose: STATE SERVICE {"status":"stop","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is2-ssl.mzstatic.com/image/thumb/Music113/v4/f1/91/ef/f191effe-4cf2-932b-f2cf-a724454d2d49/source/600x600bb.jpg","name":"Oasis - Don't Look Back In Anger","title":"Don't Look Back In Anger","artist":"90s90s Hits","album":"","streaming":true,"disableUiControls":true,"duration":"282","seek":518052628,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} May 12 21:03:48 volumio volumio[1042]: verbose: CURRENT POSITION 0 May 12 21:03:48 volumio volumio[1042]: info: CoreStateMachine::syncState stateService stop May 12 21:03:48 volumio volumio[1042]: info: CoreStateMachine::syncState currentStatus stop May 12 21:03:48 volumio volumio[1042]: info: CoreStateMachine::pushState May 12 21:03:48 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:48 volumio volumio[1042]: info: CoreCommandRouter::volumioPushState May 12 21:03:48 volumio volumio[1042]: info: No code May 12 21:03:48 volumio volumio[1042]: info: CoreStateMachine::pushState May 12 21:03:48 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:48 volumio volumio[1042]: info: CoreCommandRouter::volumioPushState May 12 21:03:48 volumio volumio[1042]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 May 12 21:03:48 volumio volumio[1042]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 May 12 21:03:48 volumio volumio[1042]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 May 12 21:03:49 volumio volumio[1042]: info: [1747065829248] [80s80s] received new event containing 2 songs. May 12 21:03:49 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand stop May 12 21:03:49 volumio volumio[1042]: info: sendMpdCommand stop took 1 milliseconds May 12 21:03:49 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand clear May 12 21:03:49 volumio volumio[1042]: info: May 12 21:03:49 volumio volumio[1042]: ---------------------------- MPD announces system playlist update May 12 21:03:49 volumio volumio[1042]: info: Ignoring MPD Status Update May 12 21:03:49 volumio volumio[1042]: info: sendMpdCommand clear took 2 milliseconds May 12 21:03:49 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand consume 1 May 12 21:03:49 volumio volumio[1042]: info: May 12 21:03:49 volumio volumio[1042]: ---------------------------- MPD announces system playlist update May 12 21:03:49 volumio volumio[1042]: info: Ignoring MPD Status Update May 12 21:03:49 volumio volumio[1042]: error: updateQueue error: null May 12 21:03:49 volumio volumio[1042]: info: May 12 21:03:49 volumio volumio[1042]: ---------------------------- MPD announces state update: options May 12 21:03:49 volumio volumio[1042]: error: updateQueue error: null May 12 21:03:49 volumio volumio[1042]: info: ------------------------------ 4ms May 12 21:03:49 volumio volumio[1042]: info: sendMpdCommand consume 1 took 3 milliseconds May 12 21:03:49 volumio volumio[1042]: info: ControllerMpd::getState May 12 21:03:49 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand status May 12 21:03:49 volumio volumio[1042]: info: ------------------------------ 3ms May 12 21:03:49 volumio volumio[1042]: info: [1747065829255] [80s80s] adding url: http://streams.90s90s.de/pop/mp3-192/volumio May 12 21:03:49 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand add "http://streams.90s90s.de/pop/mp3-192/volumio" May 12 21:03:49 volumio volumio[1042]: info: May 12 21:03:49 volumio volumio[1042]: ---------------------------- MPD announces state update: options May 12 21:03:49 volumio volumio[1042]: info: ControllerMpd::getState May 12 21:03:49 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand status May 12 21:03:49 volumio volumio[1042]: info: May 12 21:03:49 volumio volumio[1042]: ---------------------------- MPD announces system playlist update May 12 21:03:49 volumio volumio[1042]: info: Ignoring MPD Status Update May 12 21:03:49 volumio volumio[1042]: info: sendMpdCommand status took 3 milliseconds May 12 21:03:49 volumio volumio[1042]: info: sendMpdCommand add "http://streams.90s90s.de/pop/mp3-192/volumio" took 2 milliseconds May 12 21:03:49 volumio volumio[1042]: info: sendMpdCommand status took 2 milliseconds May 12 21:03:49 volumio volumio[1042]: verbose: ControllerMpd::parseState May 12 21:03:49 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand play May 12 21:03:49 volumio volumio[1042]: verbose: ControllerMpd::parseState May 12 21:03:49 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:49 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:49 volumio volumio[1042]: info: CoreStateMachine::pushState May 12 21:03:49 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:49 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 21:03:49 volumio volumio[1042]: info: CoreCommandRouter::volumioPushState May 12 21:03:49 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:49 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:49 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:49 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:49 volumio volumio[1042]: info: CoreStateMachine::pushState May 12 21:03:49 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:49 volumio volumio[1042]: info: CoreCommandRouter::volumioPushState May 12 21:03:49 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:49 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:49 volumio volumio[1042]: info: ------------------------------ 21ms May 12 21:03:49 volumio volumio[1042]: info: ------------------------------ 24ms May 12 21:03:49 volumio volumio[1042]: info: May 12 21:03:49 volumio volumio[1042]: ---------------------------- MPD announces system playlist update May 12 21:03:49 volumio volumio[1042]: info: Ignoring MPD Status Update May 12 21:03:49 volumio volumio[1042]: info: ------------------------------ 24ms May 12 21:03:49 volumio volumio[1042]: info: sendMpdCommand play took 19 milliseconds May 12 21:03:49 volumio volumio[1042]: info: ------------------------------ 2ms May 12 21:03:49 volumio volumio[1042]: info: [1747065829282] [80s80s] Pushing the next song state: Oasis - Don't Look Back In Anger May 12 21:03:49 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:49 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:49 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:49 volumio volumio[1042]: verbose: STATE SERVICE {"status":"play","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is2-ssl.mzstatic.com/image/thumb/Music113/v4/f1/91/ef/f191effe-4cf2-932b-f2cf-a724454d2d49/source/600x600bb.jpg","name":"Oasis - Don't Look Back In Anger","title":"Don't Look Back In Anger","artist":"90s90s Hits","album":"","streaming":true,"disableUiControls":true,"duration":"282","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} May 12 21:03:49 volumio volumio[1042]: verbose: CURRENT POSITION 0 May 12 21:03:49 volumio volumio[1042]: info: CoreStateMachine::syncState stateService play May 12 21:03:49 volumio volumio[1042]: info: CoreStateMachine::syncState currentStatus stop May 12 21:03:49 volumio volumio[1042]: info: [1747065829283] [80s80s] PlayNextTrack API delay: 30 May 12 21:03:49 volumio volumio[1042]: info: [1747065829286] [80s80s] Setting timer to: 282000 milliseconds. May 12 21:03:49 volumio volumio[1042]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 May 12 21:03:49 volumio volumio[1042]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 May 12 21:03:49 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:49 volumio volumio[1042]: info: CorePlayQueue::getTrack 1 May 12 21:03:52 volumio volumio[1042]: info: May 12 21:03:52 volumio volumio[1042]: ---------------------------- MPD announces state update: player May 12 21:03:52 volumio volumio[1042]: info: ControllerMpd::getState May 12 21:03:52 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand status May 12 21:03:52 volumio volumio[1042]: info: May 12 21:03:52 volumio volumio[1042]: ---------------------------- MPD announces state update: player May 12 21:03:52 volumio volumio[1042]: info: ControllerMpd::getState May 12 21:03:52 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand status May 12 21:03:52 volumio volumio[1042]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 12 21:03:52 volumio volumio[1042]: info: FusionDsp - ---- read samplerate from file: 44100 May 12 21:03:52 volumio volumio[1042]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 12 21:03:52 volumio volumio[1042]: info: FusionDsp - Effects disabled May 12 21:03:52 volumio volumio[1042]: info: May 12 21:03:52 volumio volumio[1042]: ---------------------------- MPD announces state update: player May 12 21:03:52 volumio volumio[1042]: info: sendMpdCommand status took 16 milliseconds May 12 21:03:52 volumio volumio[1042]: info: ControllerMpd::getState May 12 21:03:52 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand status May 12 21:03:52 volumio volumio[1042]: info: sendMpdCommand status took 14 milliseconds May 12 21:03:52 volumio volumio[1042]: verbose: ControllerMpd::parseState May 12 21:03:52 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 21:03:52 volumio volumio[1042]: verbose: ControllerMpd::parseState May 12 21:03:52 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 21:03:52 volumio volumio[1042]: info: May 12 21:03:52 volumio volumio[1042]: ---------------------------- MPD announces state update: player May 12 21:03:52 volumio volumio[1042]: info: ControllerMpd::getState May 12 21:03:52 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand status May 12 21:03:52 volumio volumio[1042]: info: sendMpdCommand status took 3 milliseconds May 12 21:03:52 volumio volumio[1042]: info: sendMpdCommand playlistinfo took 3 milliseconds May 12 21:03:52 volumio volumio[1042]: info: sendMpdCommand playlistinfo took 3 milliseconds May 12 21:03:52 volumio volumio[1042]: info: sendMpdCommand status took 2 milliseconds May 12 21:03:52 volumio volumio[1042]: verbose: ControllerMpd::parseState May 12 21:03:52 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 21:03:52 volumio volumio[1042]: verbose: ControllerMpd::parseTrackInfo May 12 21:03:52 volumio volumio[1042]: verbose: ControllerMpd::parseTrackInfo May 12 21:03:52 volumio volumio[1042]: verbose: ControllerMpd::parseState May 12 21:03:52 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 21:03:52 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:52 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:52 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:52 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:52 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:52 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:52 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:52 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:52 volumio volumio[1042]: info: ------------------------------ 24ms May 12 21:03:52 volumio volumio[1042]: info: ------------------------------ 23ms May 12 21:03:52 volumio volumio[1042]: info: sendMpdCommand playlistinfo took 4 milliseconds May 12 21:03:52 volumio volumio[1042]: info: sendMpdCommand playlistinfo took 3 milliseconds May 12 21:03:52 volumio volumio[1042]: verbose: ControllerMpd::parseTrackInfo May 12 21:03:52 volumio volumio[1042]: verbose: ControllerMpd::parseTrackInfo May 12 21:03:52 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:52 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:52 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:52 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:52 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:52 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:52 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:52 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:52 volumio volumio[1042]: info: ------------------------------ 11ms May 12 21:03:52 volumio volumio[1042]: info: ------------------------------ 9ms May 12 21:03:52 volumio volumio[1042]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 12 21:03:52 volumio volumio[1042]: info: May 12 21:03:52 volumio volumio[1042]: ---------------------------- MPD announces system playlist update May 12 21:03:52 volumio volumio[1042]: info: Ignoring MPD Status Update May 12 21:03:52 volumio volumio[1042]: info: May 12 21:03:52 volumio volumio[1042]: ---------------------------- MPD announces state update: player May 12 21:03:52 volumio volumio[1042]: info: ControllerMpd::getState May 12 21:03:52 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand status May 12 21:03:52 volumio volumio[1042]: info: May 12 21:03:52 volumio volumio[1042]: ---------------------------- MPD announces system playlist update May 12 21:03:52 volumio volumio[1042]: info: Ignoring MPD Status Update May 12 21:03:52 volumio volumio[1042]: info: May 12 21:03:52 volumio volumio[1042]: ---------------------------- MPD announces state update: player May 12 21:03:52 volumio volumio[1042]: info: ControllerMpd::getState May 12 21:03:52 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand status May 12 21:03:52 volumio volumio[1042]: info: ------------------------------ 6ms May 12 21:03:52 volumio volumio[1042]: info: sendMpdCommand status took 7 milliseconds May 12 21:03:52 volumio volumio[1042]: info: ------------------------------ 6ms May 12 21:03:52 volumio volumio[1042]: info: sendMpdCommand status took 5 milliseconds May 12 21:03:52 volumio volumio[1042]: verbose: ControllerMpd::parseState May 12 21:03:52 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 21:03:52 volumio volumio[1042]: verbose: ControllerMpd::parseState May 12 21:03:52 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 21:03:52 volumio volumio[1042]: info: sendMpdCommand playlistinfo took 1 milliseconds May 12 21:03:52 volumio volumio[1042]: info: sendMpdCommand playlistinfo took 1 milliseconds May 12 21:03:52 volumio volumio[1042]: verbose: ControllerMpd::parseTrackInfo May 12 21:03:52 volumio volumio[1042]: verbose: ControllerMpd::parseTrackInfo May 12 21:03:52 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:52 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:52 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:52 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:52 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:52 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:52 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:52 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:52 volumio volumio[1042]: info: ------------------------------ 12ms May 12 21:03:52 volumio volumio[1042]: info: ------------------------------ 10ms May 12 21:03:54 volumio volumio[1042]: info: May 12 21:03:54 volumio volumio[1042]: ---------------------------- MPD announces system playlist update May 12 21:03:54 volumio volumio[1042]: info: Ignoring MPD Status Update May 12 21:03:54 volumio volumio[1042]: info: May 12 21:03:54 volumio volumio[1042]: ---------------------------- MPD announces state update: player May 12 21:03:54 volumio volumio[1042]: info: ControllerMpd::getState May 12 21:03:54 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand status May 12 21:03:54 volumio volumio[1042]: info: May 12 21:03:54 volumio volumio[1042]: ---------------------------- MPD announces system playlist update May 12 21:03:54 volumio volumio[1042]: info: Ignoring MPD Status Update May 12 21:03:54 volumio volumio[1042]: info: May 12 21:03:54 volumio volumio[1042]: ---------------------------- MPD announces state update: player May 12 21:03:54 volumio volumio[1042]: info: ControllerMpd::getState May 12 21:03:54 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand status May 12 21:03:54 volumio volumio[1042]: info: ------------------------------ 3ms May 12 21:03:54 volumio volumio[1042]: info: sendMpdCommand status took 3 milliseconds May 12 21:03:54 volumio volumio[1042]: info: ------------------------------ 2ms May 12 21:03:54 volumio volumio[1042]: info: sendMpdCommand status took 1 milliseconds May 12 21:03:54 volumio volumio[1042]: verbose: ControllerMpd::parseState May 12 21:03:54 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 21:03:54 volumio volumio[1042]: verbose: ControllerMpd::parseState May 12 21:03:54 volumio volumio[1042]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 21:03:54 volumio volumio[1042]: info: sendMpdCommand playlistinfo took 1 milliseconds May 12 21:03:54 volumio volumio[1042]: info: sendMpdCommand playlistinfo took 1 milliseconds May 12 21:03:54 volumio volumio[1042]: verbose: ControllerMpd::parseTrackInfo May 12 21:03:54 volumio volumio[1042]: verbose: ControllerMpd::parseTrackInfo May 12 21:03:54 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:54 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:54 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:54 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:54 volumio volumio[1042]: info: ControllerMpd::pushState May 12 21:03:54 volumio volumio[1042]: info: CoreCommandRouter::servicePushState May 12 21:03:54 volumio volumio[1042]: info: CorePlayQueue::getTrack 0 May 12 21:03:54 volumio volumio[1042]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd May 12 21:03:54 volumio volumio[1042]: info: ------------------------------ 8ms May 12 21:03:54 volumio volumio[1042]: info: ------------------------------ 6ms May 12 21:04:19 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 12 21:04:19 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 12 21:04:20 volumio ntpd[765]: Soliciting pool server 2401:5b60:0:1::52 May 12 21:04:25 volumio volumio[1042]: info: FusionDsp - Stopping FusionDsp service May 12 21:04:25 volumio volumio[1042]: info: camilladsp stopping service pid 1768... May 12 21:04:25 volumio kernel: bcm2835_audio bcm2835_audio: failed to close VCHI service connection (status=-11) May 12 21:04:25 volumio volumio[1042]: info: camilladsp service terminated, instance 1 May 12 21:04:25 volumio volumio[1042]: info: Disabling plugin fusiondsp May 12 21:04:25 volumio volumio[1042]: info: Preparing to generate the ALSA configuration file May 12 21:04:25 volumio sudo[1920]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop fusiondsp.service May 12 21:04:25 volumio sudo[1920]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 21:04:25 volumio volumio[1042]: info: Asound.conf file written May 12 21:04:25 volumio systemd[1]: Stopping FusionDsp Daemon... May 12 21:04:25 volumio volumio[1345]: Backend configuration: May 12 21:04:25 volumio volumio[1345]: active_config: /data/configuration/audio_interface/fusiondsp/camilladsp.yml May 12 21:04:25 volumio volumio[1345]: active_config_txt: null May 12 21:04:25 volumio volumio[1345]: camilla_host: 127.0.0.1 May 12 21:04:25 volumio volumio[1345]: camilla_port: 9876 May 12 21:04:25 volumio volumio[1345]: coeff_dir: /data/INTERNAL/FusionDsp/filters May 12 21:04:25 volumio volumio[1345]: config_dir: /data/configuration/audio_interface/fusiondsp May 12 21:04:25 volumio volumio[1345]: default_config: /data/configuration/audio_interface/fusiondsp/camilladsp.yml May 12 21:04:25 volumio volumio[1345]: log_file: /tmp/camilladsp.log May 12 21:04:25 volumio volumio[1345]: on_get_active_config: null May 12 21:04:25 volumio volumio[1345]: on_set_active_config: null May 12 21:04:25 volumio volumio[1345]: port: 5011 May 12 21:04:25 volumio volumio[1345]: supported_capture_types: null May 12 21:04:25 volumio volumio[1345]: supported_playback_types: null May 12 21:04:25 volumio volumio[1345]: update_config_symlink: false May 12 21:04:25 volumio volumio[1345]: update_config_txt: false May 12 21:04:25 volumio volumio[1345]: ======== Running on http://0.0.0.0:5011 ======== May 12 21:04:25 volumio volumio[1345]: (Press CTRL+C to quit) May 12 21:04:25 volumio sudo[1923]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf May 12 21:04:25 volumio sudo[1923]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 21:04:25 volumio sudo[1923]: pam_unix(sudo:session): session closed for user root May 12 21:04:25 volumio volumio[1042]: info: Output device has changed, restarting MPD May 12 21:04:25 volumio sudo[1928]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 12 21:04:25 volumio volumio[1042]: info: Output device has changed, restarting Shairport Sync May 12 21:04:25 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:04:25 volumio sudo[1928]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 21:04:25 volumio sudo[1928]: pam_unix(sudo:session): session closed for user root May 12 21:04:25 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 21:04:25 volumio systemd[1]: fusiondsp.service: Succeeded. May 12 21:04:25 volumio systemd[1]: Stopped FusionDsp Daemon. May 12 21:04:25 volumio sudo[1930]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 12 21:04:25 volumio sudo[1930]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 21:04:25 volumio sudo[1920]: pam_unix(sudo:session): session closed for user root May 12 21:04:25 volumio systemd[1]: Stopping Music Player Daemon... May 12 21:04:25 volumio volumio[1042]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 12 21:04:25 volumio volumio[1042]: info: Done. May 12 21:04:25 volumio volumio[1042]: info: MPD Permissions set May 12 21:04:25 volumio volumio[1042]: info: FusionDsp - Reporting Fusion DSP Disabled May 12 21:04:25 volumio volumio[1042]: info: Removing fusiondspeq DSP Signal Path Element May 12 21:04:25 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:04:25 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:04:25 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:04:25 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:04:25 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:04:25 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:04:25 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:04:25 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:04:25 volumio systemd[1]: mpd.service: Succeeded. May 12 21:04:25 volumio systemd[1]: Stopped Music Player Daemon. May 12 21:04:25 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 21:04:25 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:04:25 volumio volumio[1042]: info: Starting Shairport Sync May 12 21:04:25 volumio sudo[1942]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 12 21:04:25 volumio sudo[1942]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 21:04:25 volumio systemd[1]: Starting Music Player Daemon... May 12 21:04:25 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 12 21:04:25 volumio systemd[1]: shairport-sync.service: Succeeded. May 12 21:04:25 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 12 21:04:25 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 12 21:04:25 volumio sudo[1942]: pam_unix(sudo:session): session closed for user root May 12 21:04:25 volumio volumio[1042]: info: Shairport-Sync Started May 12 21:04:25 volumio sudo[1936]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 12 21:04:25 volumio sudo[1936]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 21:04:25 volumio sudo[1936]: pam_unix(sudo:session): session closed for user root May 12 21:04:26 volumio mpd[1948]: May 12 21:04 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 12 21:04:26 volumio systemd[1]: Started Music Player Daemon. May 12 21:04:26 volumio sudo[1930]: pam_unix(sudo:session): session closed for user root May 12 21:04:26 volumio volumio[1042]: error: updateQueue error: null May 12 21:04:27 volumio volumio[1042]: info: Enabling plugin fusiondsp May 12 21:04:27 volumio volumio[1042]: info: Loading plugin "fusiondsp"... May 12 21:04:27 volumio volumio[1042]: info: Applying required configuration parameters for plugin fusiondsp May 12 21:04:27 volumio volumio[1042]: info: Preparing to generate the ALSA configuration file May 12 21:04:27 volumio volumio[1042]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 12 21:04:27 volumio volumio[1042]: info: Reading ALSA contributions from plugins. May 12 21:04:27 volumio volumio[1042]: info: Asound.conf file written May 12 21:04:27 volumio sudo[1952]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf May 12 21:04:27 volumio sudo[1952]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 21:04:27 volumio sudo[1952]: pam_unix(sudo:session): session closed for user root May 12 21:04:27 volumio volumio[1042]: info: Output device has changed, restarting MPD May 12 21:04:28 volumio sudo[1957]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 12 21:04:28 volumio sudo[1957]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 21:04:28 volumio volumio[1042]: info: Output device has changed, restarting Shairport Sync May 12 21:04:28 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:04:28 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 21:04:28 volumio sudo[1957]: pam_unix(sudo:session): session closed for user root May 12 21:04:28 volumio sudo[1959]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 12 21:04:28 volumio sudo[1959]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 21:04:28 volumio systemd[1]: Stopping Music Player Daemon... May 12 21:04:28 volumio volumio[1042]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 12 21:04:28 volumio volumio[1042]: info: PLUGIN START: fusiondsp May 12 21:04:28 volumio volumio[1042]: info: Loading i18n strings for locale ru May 12 21:04:28 volumio systemd[1]: mpd.service: Succeeded. May 12 21:04:28 volumio systemd[1]: Stopped Music Player Daemon. May 12 21:04:28 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile May 12 21:04:28 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:04:28 volumio volumio[1042]: info: FusionDsp - mixtype--------------------- Hardware May 12 21:04:28 volumio volumio[1042]: info: Preparing to generate the ALSA configuration file May 12 21:04:28 volumio volumio[1042]: info: Done. May 12 21:04:28 volumio volumio[1042]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 12 21:04:28 volumio volumio[1042]: info: Reading ALSA contributions from plugins. May 12 21:04:28 volumio volumio[1042]: info: MPD Permissions set May 12 21:04:28 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:04:28 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:04:28 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:04:28 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:04:28 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:04:28 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:04:28 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:04:28 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:04:28 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 21:04:28 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:04:28 volumio volumio[1042]: info: Starting Shairport Sync May 12 21:04:28 volumio systemd[1]: Starting Music Player Daemon... May 12 21:04:28 volumio volumio[1042]: info: Asound.conf file unchanged, so no further update is needed May 12 21:04:28 volumio volumio[1042]: info: Output device has changed, restarting MPD May 12 21:04:28 volumio sudo[1971]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 12 21:04:28 volumio sudo[1971]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 21:04:28 volumio sudo[1974]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 12 21:04:28 volumio sudo[1974]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 21:04:28 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 12 21:04:28 volumio sudo[1974]: pam_unix(sudo:session): session closed for user root May 12 21:04:28 volumio volumio[1042]: info: Output device has changed, restarting Shairport Sync May 12 21:04:28 volumio systemd[1]: shairport-sync.service: Succeeded. May 12 21:04:28 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 12 21:04:28 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:04:28 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 21:04:28 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 12 21:04:28 volumio sudo[1971]: pam_unix(sudo:session): session closed for user root May 12 21:04:28 volumio sudo[1977]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 12 21:04:28 volumio sudo[1977]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 21:04:28 volumio sudo[1965]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 12 21:04:28 volumio sudo[1965]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 21:04:28 volumio sudo[1965]: pam_unix(sudo:session): session closed for user root May 12 21:04:28 volumio systemd[1]: mpd.service: Succeeded. May 12 21:04:28 volumio systemd[1]: Stopped Music Player Daemon. May 12 21:04:28 volumio volumio[1042]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 12 21:04:28 volumio systemd[1]: Starting Music Player Daemon... May 12 21:04:28 volumio volumio[1042]: info: MPD Permissions set May 12 21:04:28 volumio volumio[1042]: info: Shairport-Sync Started May 12 21:04:28 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:04:28 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:04:28 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:04:28 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:04:28 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:04:28 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 21:04:28 volumio volumio[1042]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 21:04:28 volumio volumio[1042]: info: Starting Shairport Sync May 12 21:04:28 volumio sudo[1992]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 12 21:04:28 volumio sudo[1992]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 21:04:28 volumio sudo[1984]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 12 21:04:28 volumio sudo[1984]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 21:04:28 volumio sudo[1984]: pam_unix(sudo:session): session closed for user root May 12 21:04:28 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 12 21:04:28 volumio systemd[1]: shairport-sync.service: Succeeded. May 12 21:04:28 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 12 21:04:28 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 12 21:04:28 volumio sudo[1992]: pam_unix(sudo:session): session closed for user root May 12 21:04:28 volumio volumio[1042]: info: Shairport-Sync Started May 12 21:04:29 volumio mpd[1995]: May 12 21:04 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 12 21:04:29 volumio systemd[1]: Started Music Player Daemon. May 12 21:04:29 volumio sudo[1977]: pam_unix(sudo:session): session closed for user root May 12 21:04:29 volumio sudo[1959]: pam_unix(sudo:session): session closed for user root May 12 21:04:29 volumio volumio[1042]: error: MPD error: The expression evaluated to a falsy value: May 12 21:04:29 volumio volumio[1042]: assert.ok(self.idling) May 12 21:04:29 volumio volumio[1042]: error: The expression evaluated to a falsy value: May 12 21:04:29 volumio volumio[1042]: assert.ok(self.idling) May 12 21:04:29 volumio volumio[1042]: error: updateQueue error: null May 12 21:04:29 volumio volumio[1042]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 12 21:04:29 volumio volumio[1042]: TypeError: Cannot read property 'off' of undefined May 12 21:04:29 volumio volumio[1042]: at FusionDsp.onStop (/data/plugins/audio_interface/fusiondsp/index.js:107:15) May 12 21:04:29 volumio volumio[1042]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30) May 12 21:04:29 volumio volumio[1042]: at PluginManager.disableAndStopPlugin (/volumio/app/pluginmanager.js:1883:8) May 12 21:04:29 volumio volumio[1042]: at CoreCommandRouter.disableAndStopPlugin (/volumio/app/index.js:1556:29) May 12 21:04:29 volumio volumio[1042]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1401:47) May 12 21:04:29 volumio volumio[1042]: at Socket.emit (events.js:315:20) May 12 21:04:29 volumio volumio[1042]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 May 12 21:04:29 volumio volumio[1042]: at processTicksAndRejections (internal/process/task_queues.js:75:11) May 12 21:04:29 volumio volumio[1042]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 12 21:04:29 volumio sudo[2027]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-12 21:03 May 12 21:04:29 volumio sudo[2027]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 24 Apr 2025 09:33:57 AM CEST" VOLUMIO_VERSION="3.804" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="354f95cf0a6c2cbcd57b1aca3179c81c"