-- Logs begin at Thu 2019-02-14 10:11:58 GMT, end at Fri 2025-07-18 21:40:16 BST. -- Jul 18 21:39:00 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:00 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:00 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:00 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:00 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:00 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:00 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:00 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:00 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:00 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:00 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:00 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:01 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:01 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:01 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:01 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:01 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:01 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:01 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:01 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:01 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:01 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:01 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:01 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:02 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:02 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:02 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:02 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:02 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:02 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:02 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:02 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:02 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:02 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:02 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:02 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:03 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:03 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:03 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:03 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:03 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:03 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:03 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:03 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:03 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:03 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:03 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:03 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:04 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:04 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:04 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:04 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:04 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:04 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:04 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:04 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:04 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:04 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:04 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:04 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:05 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:05 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:05 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:05 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:05 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:05 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:05 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:05 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:05 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:05 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:05 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:05 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:06 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:06 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:06 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:06 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:06 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:06 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:06 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:06 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:06 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:06 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:06 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:06 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:07 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:07 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:07 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:07 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:07 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:07 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:07 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:07 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:07 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:07 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:07 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:07 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:08 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:08 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:08 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:08 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:08 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:08 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:08 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:08 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:08 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:08 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:08 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:08 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:09 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:09 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:09 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:09 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:09 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:09 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:09 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:09 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:09 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:09 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:09 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:09 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:10 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:10 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:10 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:10 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:10 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:10 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:10 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:10 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:10 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:10 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:10 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:10 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:11 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:11 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:11 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:11 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:11 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:11 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:11 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:11 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:11 richdacvolumio volumio[3782]: error: Plugin system_controller networkfs failed to complete 'onVolumioStart' in a timely fashion Jul 18 21:39:11 richdacvolumio volumio[3782]: info: Preparing to generate the ALSA configuration file Jul 18 21:39:11 richdacvolumio volumio[3782]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jul 18 21:39:11 richdacvolumio volumio[3782]: info: The plugin mpd_oled has an ALSA contribution file volumioalsa.postalsa.5.conf Jul 18 21:39:11 richdacvolumio volumio[3782]: info: Reading ALSA contributions from plugins. Jul 18 21:39:11 richdacvolumio volumio[3782]: info: Asound.conf file unchanged, so no further update is needed Jul 18 21:39:11 richdacvolumio volumio[3782]: info: Output device has changed, restarting MPD Jul 18 21:39:11 richdacvolumio sudo[4555]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 18 21:39:11 richdacvolumio sudo[4555]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:11 richdacvolumio sudo[4555]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:11 richdacvolumio volumio[3782]: info: Output device has changed, restarting Shairport Sync Jul 18 21:39:11 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:11 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 21:39:11 richdacvolumio sudo[4558]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 18 21:39:11 richdacvolumio sudo[4558]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:11 richdacvolumio systemd[1]: Stopping MPD OLED Plugin... Jul 18 21:39:11 richdacvolumio systemd[1]: mpd_oled_plugin.service: Main process exited, code=killed, status=15/TERM Jul 18 21:39:11 richdacvolumio systemd[1]: mpd_oled_plugin.service: Succeeded. Jul 18 21:39:11 richdacvolumio systemd[1]: Stopped MPD OLED Plugin. Jul 18 21:39:11 richdacvolumio systemd[1]: Stopping Music Player Daemon... Jul 18 21:39:11 richdacvolumio volumio[3782]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 18 21:39:11 richdacvolumio volumio[3782]: info: ___________ START PLUGINS ___________ Jul 18 21:39:11 richdacvolumio volumio[3782]: info: ControllerMpd::onStart: Initializing MPD Jul 18 21:39:11 richdacvolumio volumio[3782]: info: Creating MPD Configuration file Jul 18 21:39:11 richdacvolumio systemd[1]: mpd.service: Succeeded. Jul 18 21:39:11 richdacvolumio systemd[1]: Stopped Music Player Daemon. Jul 18 21:39:11 richdacvolumio sudo[4565]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 18 21:39:11 richdacvolumio sudo[4565]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:11 richdacvolumio systemd[1]: Starting Music Player Daemon... Jul 18 21:39:11 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 18 21:39:11 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 18 21:39:11 richdacvolumio volumio[3782]: info: [1752871151864] CoreMusicLibrary::Adding element Media Servers Jul 18 21:39:11 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 18 21:39:11 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:11 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 21:39:11 richdacvolumio sudo[4565]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:11 richdacvolumio sudo[4568]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 18 21:39:11 richdacvolumio sudo[4568]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:11 richdacvolumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Jul 18 21:39:11 richdacvolumio systemd[1]: mpd.service: Succeeded. Jul 18 21:39:11 richdacvolumio systemd[1]: Stopped Music Player Daemon. Jul 18 21:39:11 richdacvolumio systemd[1]: Starting Music Player Daemon... Jul 18 21:39:11 richdacvolumio volumio[3782]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 18 21:39:11 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:11 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 21:39:11 richdacvolumio volumio[3782]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 18 21:39:11 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 18 21:39:11 richdacvolumio volumio[3782]: info: [1752871151968] CoreMusicLibrary::Adding element Last_100 Jul 18 21:39:11 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 18 21:39:11 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 18 21:39:11 richdacvolumio volumio[3782]: info: [1752871151970] CoreMusicLibrary::Adding element Webradio Jul 18 21:39:11 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 18 21:39:11 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 18 21:39:11 richdacvolumio volumio[3782]: info: Initializing BBC Radios Jul 18 21:39:11 richdacvolumio sudo[4573]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jul 18 21:39:11 richdacvolumio sudo[4573]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:11 richdacvolumio sudo[4573]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 18 21:39:12 richdacvolumio volumio[3782]: info: [1752871152062] CoreMusicLibrary::Adding element Bandcamp Discover Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 18 21:39:12 richdacvolumio volumio[3782]: Cannot find translation for source Bandcamp Discover Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 18 21:39:12 richdacvolumio volumio[3782]: info: [1752871152069] CoreMusicLibrary::Adding element Mixcloud Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 18 21:39:12 richdacvolumio volumio[3782]: Cannot find translation for source Bandcamp Discover Jul 18 21:39:12 richdacvolumio volumio[3782]: Cannot find translation for source Mixcloud Jul 18 21:39:12 richdacvolumio volumio[3782]: info: Creating Spotify config file Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 18 21:39:12 richdacvolumio volumio[3782]: info: [1752871152129] CoreMusicLibrary::Adding element YouTube2 Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 18 21:39:12 richdacvolumio volumio[3782]: Cannot find translation for source Bandcamp Discover Jul 18 21:39:12 richdacvolumio volumio[3782]: Cannot find translation for source Mixcloud Jul 18 21:39:12 richdacvolumio volumio[3782]: Cannot find translation for source YouTube2 Jul 18 21:39:12 richdacvolumio volumio[3782]: info: [now-playing] ConfigUpdater: config is up to date. Jul 18 21:39:12 richdacvolumio volumio[3782]: info: Loading i18n strings for locale en Jul 18 21:39:12 richdacvolumio volumio[3782]: info: Plugin mpdoutput has duplicated i18n key SAVE. It is ignored. Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:12 richdacvolumio volumio[3782]: info: FusionDsp - mixtype--------------------- Hardware Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 18 21:39:12 richdacvolumio volumio[3782]: info: [1752871152196] CoreMusicLibrary::Adding element 80s80s Radio Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 18 21:39:12 richdacvolumio volumio[3782]: Cannot find translation for source Bandcamp Discover Jul 18 21:39:12 richdacvolumio volumio[3782]: Cannot find translation for source Mixcloud Jul 18 21:39:12 richdacvolumio volumio[3782]: Cannot find translation for source YouTube2 Jul 18 21:39:12 richdacvolumio volumio[3782]: Cannot find translation for source 80s80s Radio Jul 18 21:39:12 richdacvolumio volumio[3782]: info: Stopping AccessToken refresher cron for DMD2 Music Jul 18 21:39:12 richdacvolumio volumio[3782]: info: AccessToken refresher cron started for DMD2 Music Jul 18 21:39:12 richdacvolumio volumio[3782]: info: Loading i18n strings for locale en Jul 18 21:39:12 richdacvolumio volumio[3782]: info: Plugin mpdoutput has duplicated i18n key SAVE. It is ignored. Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 18 21:39:12 richdacvolumio volumio[3782]: info: [1752871152267] CoreMusicLibrary::Adding element Mother Earth Radio Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 18 21:39:12 richdacvolumio volumio[3782]: Cannot find translation for source Bandcamp Discover Jul 18 21:39:12 richdacvolumio volumio[3782]: Cannot find translation for source Mixcloud Jul 18 21:39:12 richdacvolumio volumio[3782]: Cannot find translation for source YouTube2 Jul 18 21:39:12 richdacvolumio volumio[3782]: Cannot find translation for source 80s80s Radio Jul 18 21:39:12 richdacvolumio volumio[3782]: Cannot find translation for source Mother Earth Radio Jul 18 21:39:12 richdacvolumio volumio[3782]: /usr/bin/mkfifo: cannot create fifo '/tmp/mpdoledfifo': File exists Jul 18 21:39:12 richdacvolumio volumio[3782]: error: [MPD_OLED Plugin] Failed to create mpdoledfifo: Error: Command failed: /usr/bin/mkfifo -m 646 /tmp/mpdoledfifo Jul 18 21:39:12 richdacvolumio volumio[3782]: /usr/bin/mkfifo: cannot create fifo '/tmp/mpdoledfifo': File exists Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jul 18 21:39:12 richdacvolumio sudo[4594]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod +x /tmp/mpd_oled_plugin.sh Jul 18 21:39:12 richdacvolumio sudo[4594]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:12 richdacvolumio sudo[4594]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:12 richdacvolumio volumio[3782]: info: Loading i18n strings for locale en Jul 18 21:39:12 richdacvolumio volumio[3782]: info: Plugin mpdoutput has duplicated i18n key SAVE. It is ignored. Jul 18 21:39:12 richdacvolumio sudo[4597]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start mpd_oled_plugin.service Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 18 21:39:12 richdacvolumio sudo[4597]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:12 richdacvolumio volumio[3782]: info: Volumio Calling Home Jul 18 21:39:12 richdacvolumio volumio[3782]: info: Preparing to generate the ALSA configuration file Jul 18 21:39:12 richdacvolumio sudo[4603]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Jul 18 21:39:12 richdacvolumio sudo[4603]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:12 richdacvolumio sudo[4606]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Jul 18 21:39:12 richdacvolumio sudo[4606]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:12 richdacvolumio sudo[4609]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jul 18 21:39:12 richdacvolumio sudo[4603]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:12 richdacvolumio sudo[4609]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:12 richdacvolumio volumio[3782]: info: [now-playing] App is listening on port 4004. Jul 18 21:39:12 richdacvolumio systemd[1]: Reloading. Jul 18 21:39:12 richdacvolumio volumio[3782]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Jul 18 21:39:12 richdacvolumio volumio[3782]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jul 18 21:39:12 richdacvolumio volumio[3782]: info: The plugin mpd_oled has an ALSA contribution file volumioalsa.postalsa.5.conf Jul 18 21:39:12 richdacvolumio volumio[3782]: info: Reading ALSA contributions from plugins. Jul 18 21:39:12 richdacvolumio volumio[3782]: info: touch_display: Backlight interface detected. Jul 18 21:39:12 richdacvolumio volumio[3782]: info: touch_display: systemctl stop getty@tty1.service succeeded. Jul 18 21:39:12 richdacvolumio volumio[3782]: info: [MPD_OLED Plugin] Set execute permissions on /tmp/mpd_oled_plugin.sh Jul 18 21:39:12 richdacvolumio volumio[3782]: info: minidlna: Found miniDLNA version 1.2.1 Jul 18 21:39:12 richdacvolumio volumio[3782]: info: minidlna: Starting minidlna.service Jul 18 21:39:12 richdacvolumio volumio[3782]: info: MPD Permissions set Jul 18 21:39:12 richdacvolumio volumio[3782]: info: MPD Permissions set Jul 18 21:39:12 richdacvolumio sudo[4612]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start minidlna.service Jul 18 21:39:12 richdacvolumio sudo[4612]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:12 richdacvolumio volumio[3782]: info: Spotify config file written Jul 18 21:39:12 richdacvolumio volumio[3782]: info: [MPD_OLED Plugin] tmp script created /tmp/mpd_oled_plugin.sh Jul 18 21:39:12 richdacvolumio sudo[4628]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jul 18 21:39:12 richdacvolumio sudo[4628]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:12 richdacvolumio mpd[4579]: Jul 18 21:39 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jul 18 21:39:12 richdacvolumio volumio[3782]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:12 richdacvolumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 21:39:12 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:12 richdacvolumio volumio[3782]: info: Volumio called home Jul 18 21:39:12 richdacvolumio volumio[3782]: info: touch_display: Raspberry Pi Foundation touch screen detected. Jul 18 21:39:12 richdacvolumio sudo[4641]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Jul 18 21:39:13 richdacvolumio sudo[4641]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:13 richdacvolumio sudo[4641]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:13 richdacvolumio volumio[3782]: info: Starting Shairport Sync Jul 18 21:39:13 richdacvolumio sudo[4644]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+w /sys/class/backlight/rpi_backlight/brightness Jul 18 21:39:13 richdacvolumio sudo[4644]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:13 richdacvolumio sudo[4644]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:13 richdacvolumio volumio[3782]: info: Starting Shairport Sync Jul 18 21:39:13 richdacvolumio sudo[4647]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 18 21:39:13 richdacvolumio sudo[4647]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:13 richdacvolumio volumio[3782]: info: Starting Shairport Sync Jul 18 21:39:13 richdacvolumio sudo[4650]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 18 21:39:13 richdacvolumio sudo[4650]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:13 richdacvolumio volumio[3782]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Jul 18 21:39:13 richdacvolumio volumio[3782]: info: touch_display: File permissions for backlight brightness control set. Jul 18 21:39:13 richdacvolumio volumio[3782]: info: Asound.conf file unchanged, so no further update is needed Jul 18 21:39:13 richdacvolumio volumio[3782]: info: Output device has changed, restarting MPD Jul 18 21:39:13 richdacvolumio systemd[1]: /lib/systemd/system/rpc-statd.service:13: PIDFile= references path below legacy directory /var/run/, updating /var/run/rpc.statd.pid → /run/rpc.statd.pid; please update the unit file accordingly. Jul 18 21:39:13 richdacvolumio sudo[4653]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 18 21:39:13 richdacvolumio sudo[4653]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:13 richdacvolumio sudo[4658]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 18 21:39:13 richdacvolumio sudo[4658]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:13 richdacvolumio volumio[3782]: info: Output device has changed, restarting Shairport Sync Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 21:39:13 richdacvolumio volumio[3782]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 18 21:39:13 richdacvolumio volumio[3782]: info: Preparing to generate the ALSA configuration file Jul 18 21:39:13 richdacvolumio sudo[4658]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:13 richdacvolumio sudo[4661]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 18 21:39:13 richdacvolumio sudo[4661]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:13 richdacvolumio volumio[3782]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jul 18 21:39:13 richdacvolumio volumio[3782]: info: The plugin mpd_oled has an ALSA contribution file volumioalsa.postalsa.5.conf Jul 18 21:39:13 richdacvolumio volumio[3782]: info: Reading ALSA contributions from plugins. Jul 18 21:39:13 richdacvolumio volumio[3782]: info: MPD Permissions set Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:13 richdacvolumio volumio[3782]: info: Starting Shairport Sync Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioPause Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreStateMachine::pause Jul 18 21:39:13 richdacvolumio volumio[3782]: info: mpdhttpout --- Volumio set on pause Jul 18 21:39:13 richdacvolumio volumio[3782]: info: mpdhttpout ---Configuration successfully added to mpd.conf. Jul 18 21:39:13 richdacvolumio sudo[4671]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 18 21:39:13 richdacvolumio systemd[1]: Started Music Player Daemon. Jul 18 21:39:13 richdacvolumio sudo[4671]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:13 richdacvolumio systemd[1]: Reloading. Jul 18 21:39:13 richdacvolumio sudo[4568]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:13 richdacvolumio sudo[4558]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:13 richdacvolumio sudo[4609]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:13 richdacvolumio volumio[3782]: info: Asound.conf file unchanged, so no further update is needed Jul 18 21:39:13 richdacvolumio volumio[3782]: info: Output device has changed, restarting MPD Jul 18 21:39:13 richdacvolumio sudo[4675]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 18 21:39:13 richdacvolumio sudo[4675]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:13 richdacvolumio sudo[4675]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:13 richdacvolumio volumio[3782]: info: Output device has changed, restarting Shairport Sync Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 21:39:13 richdacvolumio sudo[4678]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 18 21:39:13 richdacvolumio sudo[4678]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:13 richdacvolumio volumio[3782]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 18 21:39:13 richdacvolumio volumio[3782]: info: touch_display: systemctl daemon-reload succeeded. Jul 18 21:39:13 richdacvolumio sudo[4697]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Jul 18 21:39:13 richdacvolumio sudo[4697]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:13 richdacvolumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Jul 18 21:39:13 richdacvolumio volumio[3782]: info: MPD Permissions set Jul 18 21:39:13 richdacvolumio volumio[3782]: error: MPD error: The expression evaluated to a falsy value: Jul 18 21:39:13 richdacvolumio volumio[3782]: assert.ok(self.idling) Jul 18 21:39:13 richdacvolumio volumio[3782]: error: The expression evaluated to a falsy value: Jul 18 21:39:13 richdacvolumio volumio[3782]: assert.ok(self.idling) Jul 18 21:39:13 richdacvolumio volumio[3782]: info: MPD running with PID4579 Jul 18 21:39:13 richdacvolumio volumio[3782]: ,establishing connection Jul 18 21:39:13 richdacvolumio volumio[3782]: error: updateQueue error: null Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:13 richdacvolumio volumio[3782]: error: updateQueue error: null Jul 18 21:39:13 richdacvolumio volumio[3782]: info: Starting Shairport Sync Jul 18 21:39:13 richdacvolumio volumio[3782]: info: mpdhttpout ---Configuration successfully replaced in mpd.conf. Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioPause Jul 18 21:39:13 richdacvolumio volumio[3782]: info: CoreStateMachine::pause Jul 18 21:39:13 richdacvolumio volumio[3782]: info: mpdhttpout --- Volumio set on pause Jul 18 21:39:13 richdacvolumio systemd[1]: /lib/systemd/system/rpc-statd.service:13: PIDFile= references path below legacy directory /var/run/, updating /var/run/rpc.statd.pid → /run/rpc.statd.pid; please update the unit file accordingly. Jul 18 21:39:13 richdacvolumio sudo[4706]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 18 21:39:13 richdacvolumio sudo[4706]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:13 richdacvolumio sudo[4606]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:13 richdacvolumio volumio[3782]: info: touch_display: systemctl disable getty@tty1.service succeeded. Jul 18 21:39:13 richdacvolumio sudo[4697]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:13 richdacvolumio systemd[1]: Stopping Music Player Daemon... Jul 18 21:39:13 richdacvolumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jul 18 21:39:13 richdacvolumio systemd[1]: Stopping go-librespot Daemon... Jul 18 21:39:13 richdacvolumio sudo[4612]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:14 richdacvolumio systemd[1]: shairport-sync.service: Succeeded. Jul 18 21:39:14 richdacvolumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jul 18 21:39:14 richdacvolumio volumio[3782]: info: minidlna: systemctl start minidlna.service succeeded. Jul 18 21:39:14 richdacvolumio volumio[3782]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Jul 18 21:39:14 richdacvolumio volumio[3782]: info: touch_display: Volumio Kiosk started. Jul 18 21:39:14 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Jul 18 21:39:14 richdacvolumio systemd[1]: go-librespot-daemon.service: Succeeded. Jul 18 21:39:14 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jul 18 21:39:14 richdacvolumio systemd[1]: mpd.service: Succeeded. Jul 18 21:39:14 richdacvolumio systemd[1]: Stopped Music Player Daemon. Jul 18 21:39:14 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:14 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:14 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:14 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:14 richdacvolumio systemd[1]: Starting Music Player Daemon... Jul 18 21:39:14 richdacvolumio systemd[1]: Started go-librespot Daemon. Jul 18 21:39:14 richdacvolumio go-librespot[4712]: Librespot-go daemon starting... Jul 18 21:39:14 richdacvolumio sudo[4628]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:14 richdacvolumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jul 18 21:39:14 richdacvolumio sudo[4706]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:14 richdacvolumio sudo[4671]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:14 richdacvolumio sudo[4653]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:14 richdacvolumio sudo[4647]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:14 richdacvolumio sudo[4650]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:14 richdacvolumio go-librespot[4712]: time="2025-07-18T21:39:14+01:00" level=info msg="generated new device id: 3df5318f651dd763d61d11dfdc1ae75cc5cc94c6" Jul 18 21:39:14 richdacvolumio go-librespot[4712]: time="2025-07-18T21:39:14+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jul 18 21:39:14 richdacvolumio volumio[3782]: info: Shairport-Sync Started Jul 18 21:39:14 richdacvolumio volumio[3782]: Error adding Membership: Error: addMembership EINVAL Jul 18 21:39:14 richdacvolumio volumio[3782]: info: Shairport-Sync Started Jul 18 21:39:14 richdacvolumio volumio[3782]: info: Shairport-Sync Started Jul 18 21:39:14 richdacvolumio volumio[3782]: info: Shairport-Sync Started Jul 18 21:39:14 richdacvolumio volumio[3782]: info: Shairport-Sync Started Jul 18 21:39:14 richdacvolumio sudo[4709]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jul 18 21:39:14 richdacvolumio sudo[4709]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:14 richdacvolumio sudo[4709]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:14 richdacvolumio volumio[3782]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists Jul 18 21:39:14 richdacvolumio volumio[3782]: error: FusionDsp - ----failed to create fusiondspfifo :Error: Command failed: /bin/touch /tmp/fusiondsp_stream_params.log && /bin/chmod 666 /tmp/fusiondsp_stream_params.log && /bin/touch /tmp/camilladsp.log && /bin/chmod 666 /tmp/camilladsp.log && /usr/bin/mkfifo -m 646 /tmp/fusiondspfifo Jul 18 21:39:14 richdacvolumio volumio[3782]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists Jul 18 21:39:14 richdacvolumio volumio[3782]: info: camilladsp spawned new process with pid 4733, instance 1, run: true Jul 18 21:39:14 richdacvolumio volumio[3782]: info: camilladsp service started and running in background, instance 1 Jul 18 21:39:14 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:14 richdacvolumio volumio[3782]: cannot open device 'volumioHw': Device or resource busy Jul 18 21:39:14 richdacvolumio volumio[3782]: error: FusionDsp - ----Hw detection failed :Error: Command failed: /data/plugins/audio_interface/fusiondsp/hw_params volumioHw >/data/configuration/audio_interface/fusiondsp/hwinfo.json Jul 18 21:39:14 richdacvolumio volumio[3782]: cannot open device 'volumioHw': Device or resource busy Jul 18 21:39:14 richdacvolumio volumio[3782]: info: FusionDsp loaded Jul 18 21:39:14 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 18 21:39:14 richdacvolumio sudo[4743]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Jul 18 21:39:14 richdacvolumio sudo[4743]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:14 richdacvolumio volumio[3782]: info: FusionDsp - Reporting Fusion DSP Enabled Jul 18 21:39:14 richdacvolumio volumio[3782]: info: Adding Signal Path Element [object Object] Jul 18 21:39:14 richdacvolumio volumio[3782]: info: Adding fusiondspeq DSP Signal Path Element Jul 18 21:39:14 richdacvolumio volumio[3782]: info: FusionDsp - ---- installed callbackRead Jul 18 21:39:14 richdacvolumio volumio[3782]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jul 18 21:39:14 richdacvolumio volumio[3782]: info: touch_display: X display number found: 0 Jul 18 21:39:14 richdacvolumio volumio[3782]: info: touch_display: X display number found: 0 Jul 18 21:39:14 richdacvolumio go-librespot[4712]: time="2025-07-18T21:39:14+01:00" level=debug msg="obtained new client token: AACaiIjQ1H3JSYyVQdvdrOKQehgwWKHN0EKJf7oXfjO2KNAYP2WSBhkEJJf5VPTUvT0LyM4Pp8tfJIgii3S1tjdTdQs1uMDNJ3KcEiBrnU+DE4aNmA9a4czzuDnG8sEjUP9ICZUP2XlJJncTWrYcuDfciOIkP2wFdDA+mq6JwgaHLO9Ce4415sUMkOHh7VsgEFDvNr/8BCWMdYcBcOj99tuv4dltGWuxXFM6NzeYduCCh/HKFyBPO5a9uCW9wQ==" Jul 18 21:39:14 richdacvolumio sudo[4743]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:14 richdacvolumio volumio[3782]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Jul 18 21:39:14 richdacvolumio volumio[3782]: info: touch_display: X display number found: 0 Jul 18 21:39:14 richdacvolumio volumio[3782]: info: FusionDsp - eq1: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Biquad Jul 18 21:39:14 richdacvolumio volumio[3782]: parameters: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Peaking Jul 18 21:39:14 richdacvolumio volumio[3782]: freq: 25 Jul 18 21:39:14 richdacvolumio volumio[3782]: q: 1.1 Jul 18 21:39:14 richdacvolumio volumio[3782]: gain: 0 Jul 18 21:39:14 richdacvolumio volumio[3782]: eq2: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Biquad Jul 18 21:39:14 richdacvolumio volumio[3782]: parameters: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Peaking Jul 18 21:39:14 richdacvolumio volumio[3782]: freq: 40 Jul 18 21:39:14 richdacvolumio volumio[3782]: q: 1.1 Jul 18 21:39:14 richdacvolumio volumio[3782]: gain: 0 Jul 18 21:39:14 richdacvolumio volumio[3782]: eq3: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Biquad Jul 18 21:39:14 richdacvolumio volumio[3782]: parameters: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Peaking Jul 18 21:39:14 richdacvolumio volumio[3782]: freq: 63 Jul 18 21:39:14 richdacvolumio volumio[3782]: q: 1.1 Jul 18 21:39:14 richdacvolumio volumio[3782]: gain: 0 Jul 18 21:39:14 richdacvolumio volumio[3782]: eq4: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Biquad Jul 18 21:39:14 richdacvolumio volumio[3782]: parameters: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Peaking Jul 18 21:39:14 richdacvolumio volumio[3782]: freq: 100 Jul 18 21:39:14 richdacvolumio volumio[3782]: q: 1.1 Jul 18 21:39:14 richdacvolumio volumio[3782]: gain: 0 Jul 18 21:39:14 richdacvolumio volumio[3782]: eq5: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Biquad Jul 18 21:39:14 richdacvolumio volumio[3782]: parameters: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Peaking Jul 18 21:39:14 richdacvolumio volumio[3782]: freq: 160 Jul 18 21:39:14 richdacvolumio volumio[3782]: q: 1.1 Jul 18 21:39:14 richdacvolumio volumio[3782]: gain: 0 Jul 18 21:39:14 richdacvolumio volumio[3782]: eq6: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Biquad Jul 18 21:39:14 richdacvolumio volumio[3782]: parameters: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Peaking Jul 18 21:39:14 richdacvolumio volumio[3782]: freq: 250 Jul 18 21:39:14 richdacvolumio volumio[3782]: q: 1.1 Jul 18 21:39:14 richdacvolumio volumio[3782]: gain: 0 Jul 18 21:39:14 richdacvolumio volumio[3782]: eq7: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Biquad Jul 18 21:39:14 richdacvolumio volumio[3782]: parameters: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Peaking Jul 18 21:39:14 richdacvolumio volumio[3782]: freq: 400 Jul 18 21:39:14 richdacvolumio volumio[3782]: q: 1.1 Jul 18 21:39:14 richdacvolumio volumio[3782]: gain: 0 Jul 18 21:39:14 richdacvolumio volumio[3782]: eq8: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Biquad Jul 18 21:39:14 richdacvolumio volumio[3782]: parameters: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Peaking Jul 18 21:39:14 richdacvolumio volumio[3782]: freq: 630 Jul 18 21:39:14 richdacvolumio volumio[3782]: q: 1.1 Jul 18 21:39:14 richdacvolumio volumio[3782]: gain: 0 Jul 18 21:39:14 richdacvolumio volumio[3782]: eq9: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Biquad Jul 18 21:39:14 richdacvolumio volumio[3782]: parameters: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Peaking Jul 18 21:39:14 richdacvolumio volumio[3782]: freq: 1000 Jul 18 21:39:14 richdacvolumio volumio[3782]: q: 1.1 Jul 18 21:39:14 richdacvolumio volumio[3782]: gain: 0 Jul 18 21:39:14 richdacvolumio volumio[3782]: eq10: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Biquad Jul 18 21:39:14 richdacvolumio volumio[3782]: parameters: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Peaking Jul 18 21:39:14 richdacvolumio volumio[3782]: freq: 1600 Jul 18 21:39:14 richdacvolumio volumio[3782]: q: 1.1 Jul 18 21:39:14 richdacvolumio volumio[3782]: gain: 0 Jul 18 21:39:14 richdacvolumio volumio[3782]: eq11: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Biquad Jul 18 21:39:14 richdacvolumio volumio[3782]: parameters: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Peaking Jul 18 21:39:14 richdacvolumio volumio[3782]: freq: 2500 Jul 18 21:39:14 richdacvolumio volumio[3782]: q: 1.1 Jul 18 21:39:14 richdacvolumio volumio[3782]: gain: 0 Jul 18 21:39:14 richdacvolumio volumio[3782]: eq12: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Biquad Jul 18 21:39:14 richdacvolumio volumio[3782]: parameters: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Peaking Jul 18 21:39:14 richdacvolumio volumio[3782]: freq: 4000 Jul 18 21:39:14 richdacvolumio volumio[3782]: q: 1.1 Jul 18 21:39:14 richdacvolumio volumio[3782]: gain: 0 Jul 18 21:39:14 richdacvolumio volumio[3782]: eq13: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Biquad Jul 18 21:39:14 richdacvolumio volumio[3782]: parameters: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Peaking Jul 18 21:39:14 richdacvolumio volumio[3782]: freq: 6300 Jul 18 21:39:14 richdacvolumio volumio[3782]: q: 1.1 Jul 18 21:39:14 richdacvolumio volumio[3782]: gain: 0 Jul 18 21:39:14 richdacvolumio volumio[3782]: eq14: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Biquad Jul 18 21:39:14 richdacvolumio volumio[3782]: parameters: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Peaking Jul 18 21:39:14 richdacvolumio volumio[3782]: freq: 10000 Jul 18 21:39:14 richdacvolumio volumio[3782]: q: 1.1 Jul 18 21:39:14 richdacvolumio volumio[3782]: gain: 0 Jul 18 21:39:14 richdacvolumio volumio[3782]: eq15: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Biquad Jul 18 21:39:14 richdacvolumio volumio[3782]: parameters: Jul 18 21:39:14 richdacvolumio volumio[3782]: type: Peaking Jul 18 21:39:14 richdacvolumio volumio[3782]: freq: 16000 Jul 18 21:39:14 richdacvolumio volumio[3782]: q: 1.1 Jul 18 21:39:14 richdacvolumio volumio[3782]: gain: 0 Jul 18 21:39:14 richdacvolumio go-librespot[4712]: time="2025-07-18T21:39:14+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jul 18 21:39:14 richdacvolumio volumio[3782]: info: touch_display: Setting screensaver timeout to 0 seconds. Jul 18 21:39:14 richdacvolumio go-librespot[4712]: time="2025-07-18T21:39:14+01:00" level=debug msg="completed keyexchange" Jul 18 21:39:14 richdacvolumio mpd[4728]: Jul 18 21:39 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jul 18 21:39:14 richdacvolumio systemd[1]: Started Music Player Daemon. Jul 18 21:39:14 richdacvolumio sudo[4661]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:14 richdacvolumio sudo[4678]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:14 richdacvolumio volumio[3782]: error: MPD error: The expression evaluated to a falsy value: Jul 18 21:39:14 richdacvolumio volumio[3782]: assert.ok(self.idling) Jul 18 21:39:14 richdacvolumio volumio[3782]: error: The expression evaluated to a falsy value: Jul 18 21:39:14 richdacvolumio volumio[3782]: assert.ok(self.idling) Jul 18 21:39:14 richdacvolumio volumio[3782]: error: updateQueue error: null Jul 18 21:39:15 richdacvolumio systemd[1]: Started MPD OLED Plugin. Jul 18 21:39:15 richdacvolumio sudo[4597]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:15 richdacvolumio volumio[3782]: info: [MPD_OLED Plugin] Started mpd_oled_plugin service Jul 18 21:39:15 richdacvolumio go-librespot[4712]: time="2025-07-18T21:39:15+01:00" level=debug msg="completed challenge" Jul 18 21:39:15 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:15 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:15 richdacvolumio go-librespot[4712]: time="2025-07-18T21:39:15+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 18 21:39:15 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 18 21:39:15 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 18 21:39:15 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:15 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:15 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:15 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:15 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:15 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:15 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Jul 18 21:39:15 richdacvolumio sudo[4766]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 18 21:39:15 richdacvolumio sudo[4766]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:15 richdacvolumio systemd[1]: Stopping MPD OLED Plugin... Jul 18 21:39:15 richdacvolumio systemd[1]: mpd_oled_plugin.service: Main process exited, code=killed, status=15/TERM Jul 18 21:39:15 richdacvolumio systemd[1]: mpd_oled_plugin.service: Succeeded. Jul 18 21:39:15 richdacvolumio systemd[1]: Stopped MPD OLED Plugin. Jul 18 21:39:15 richdacvolumio systemd[1]: Stopping Music Player Daemon... Jul 18 21:39:15 richdacvolumio systemd[1]: mpd.service: Succeeded. Jul 18 21:39:15 richdacvolumio systemd[1]: Stopped Music Player Daemon. Jul 18 21:39:15 richdacvolumio systemd[1]: Starting Music Player Daemon... Jul 18 21:39:15 richdacvolumio sudo[4768]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jul 18 21:39:15 richdacvolumio sudo[4768]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:15 richdacvolumio sudo[4768]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:15 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Jul 18 21:39:15 richdacvolumio sudo[4772]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 18 21:39:15 richdacvolumio sudo[4772]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:15 richdacvolumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Jul 18 21:39:15 richdacvolumio systemd[1]: mpd.service: Succeeded. Jul 18 21:39:15 richdacvolumio systemd[1]: Stopped Music Player Daemon. Jul 18 21:39:15 richdacvolumio systemd[1]: Starting Music Player Daemon... Jul 18 21:39:15 richdacvolumio sudo[4774]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jul 18 21:39:15 richdacvolumio sudo[4774]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:15 richdacvolumio sudo[4774]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:16 richdacvolumio mpd[4776]: Jul 18 21:39 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jul 18 21:39:16 richdacvolumio systemd[1]: Started Music Player Daemon. Jul 18 21:39:16 richdacvolumio sudo[4772]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:16 richdacvolumio sudo[4766]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:16 richdacvolumio volumio[3782]: error: MPD error: The expression evaluated to a falsy value: Jul 18 21:39:16 richdacvolumio volumio[3782]: assert.ok(self.idling) Jul 18 21:39:16 richdacvolumio volumio[3782]: error: The expression evaluated to a falsy value: Jul 18 21:39:16 richdacvolumio volumio[3782]: assert.ok(self.idling) Jul 18 21:39:16 richdacvolumio volumio[3782]: error: updateQueue error: null Jul 18 21:39:16 richdacvolumio systemd[1]: Started MPD OLED Plugin. Jul 18 21:39:16 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:16 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:16 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:16 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:16 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:16 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:16 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:16 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:17 richdacvolumio volumio[3782]: info: go-librespot daemon successfully initialized Jul 18 21:39:17 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:17 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:17 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:17 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:17 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:17 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:17 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:17 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:17 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:17 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:17 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:17 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:17 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:17 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:18 richdacvolumio volumio[3782]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Jul 18 21:39:18 richdacvolumio volumio[3782]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jul 18 21:39:18 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:18 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:18 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:18 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:18 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 18 21:39:18 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jul 18 21:39:18 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jul 18 21:39:18 richdacvolumio systemd[1]: Started go-librespot Daemon. Jul 18 21:39:18 richdacvolumio go-librespot[4813]: Librespot-go daemon starting... Jul 18 21:39:18 richdacvolumio go-librespot[4813]: time="2025-07-18T21:39:18+01:00" level=info msg="generated new device id: d37cd56e74bbf5e6ef17eefa774ba46978675bad" Jul 18 21:39:18 richdacvolumio go-librespot[4813]: time="2025-07-18T21:39:18+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jul 18 21:39:18 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:18 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:18 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:18 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:18 richdacvolumio volumio[3782]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jul 18 21:39:18 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:18 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:18 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:18 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:19 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:19 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:19 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:19 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:19 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:19 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:19 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:19 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:19 richdacvolumio go-librespot[4813]: time="2025-07-18T21:39:19+01:00" level=debug msg="obtained new client token: AACL1MznFR/BXce8h8PukbBFlhAD+g9lRAM41ADixsyPT4aDliQVmptKu+wROXRLuJmAglu/N/WOP00nNm5HmqJGn7fsEfkyozEwG+Ch7Vl0bjkGcnCS8KT/+FaREZppFep2TdvSSLm42EZSpAH3bdzWyWPoeLoRIfxtHDVZN1imVQYMpWp1l8/xcMuJJcQFwEPMjnCqod6unfhEu6SxlAPHryQ5B8lni2vYs2h1gJG2YFdEvxCqlSuvO9w=" Jul 18 21:39:19 richdacvolumio go-librespot[4813]: time="2025-07-18T21:39:19+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 18 21:39:19 richdacvolumio go-librespot[4813]: time="2025-07-18T21:39:19+01:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.65.9:4070: connect: connection refused" Jul 18 21:39:19 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 18 21:39:19 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 18 21:39:19 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:19 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:19 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:19 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:20 richdacvolumio volumio[3782]: info: Initializing connection to go-librespot Websocket Jul 18 21:39:20 richdacvolumio volumio[3782]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 18 21:39:20 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:20 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:20 richdacvolumio volumio[3782]: info: An error occurred while refreshing Spotify Token Error: Bad Request Jul 18 21:39:20 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:20 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:20 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:20 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:20 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:20 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:20 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:20 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:20 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:20 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:21 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:21 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:21 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:21 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:21 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:21 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:21 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:21 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:21 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:21 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:21 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:21 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:22 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:22 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:22 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:22 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:22 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:22 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:22 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:22 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:22 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 18 21:39:22 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jul 18 21:39:22 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jul 18 21:39:22 richdacvolumio systemd[1]: Started go-librespot Daemon. Jul 18 21:39:22 richdacvolumio go-librespot[4913]: Librespot-go daemon starting... Jul 18 21:39:22 richdacvolumio go-librespot[4913]: time="2025-07-18T21:39:22+01:00" level=info msg="generated new device id: 2de7c86548098b60b8f4bfd0af2574dc86a2a69b" Jul 18 21:39:22 richdacvolumio go-librespot[4913]: time="2025-07-18T21:39:22+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jul 18 21:39:22 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:22 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:22 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:22 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:23 richdacvolumio volumio[3782]: info: Initializing connection to go-librespot Websocket Jul 18 21:39:23 richdacvolumio go-librespot[4913]: time="2025-07-18T21:39:23+01:00" level=debug msg="new websocket client" Jul 18 21:39:23 richdacvolumio volumio[3782]: info: Connection to go-librespot Websocket established Jul 18 21:39:23 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:23 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:23 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:23 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:23 richdacvolumio go-librespot[4913]: time="2025-07-18T21:39:23+01:00" level=debug msg="obtained new client token: AAAOz3Tx/V7Ya0CefD0hrNsRKy5SAglRpdy+wFg5S3qp8dLEt/52xXi1p3T2TPWSmaiFWexSgbOQ5zgwk0hYYAaupXzVouMI3gCHURAG7Fdv8wKD9bxl3U8RAoerAOkzbVV3oWVXDGxT3e0W3WTGmFSARIoyds/phPyExK6swVEygawKbDJF3LIvH4AmEmu87sqiGksEEt9W9XlFEdHaTJFOyMtQ72IPIkME+VsGU1eLaL/6yc4RY9g73Bywqg==" Jul 18 21:39:23 richdacvolumio volumio[3782]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jul 18 21:39:23 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioRetrievevolume Jul 18 21:39:23 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:23 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:23 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:23 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:23 richdacvolumio volumio[3782]: info: VolumeController:: Volume=100 Mute =false Jul 18 21:39:23 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:23 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:23 richdacvolumio volumio[3782]: info: CoreStateMachine::pushState Jul 18 21:39:23 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:23 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioPushState Jul 18 21:39:23 richdacvolumio volumio[3782]: info: Completed starting Core Plugins Jul 18 21:39:23 richdacvolumio volumio[3782]: info: ------------------------------------------- Jul 18 21:39:23 richdacvolumio volumio[3782]: info: ----- MyVolumio plugins startup ---- Jul 18 21:39:23 richdacvolumio volumio[3782]: info: ------------------------------------------- Jul 18 21:39:23 richdacvolumio volumio[3782]: info: [MyVolumio PluginManager] Fetching plans data.... Jul 18 21:39:23 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:23 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:23 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:23 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:23 richdacvolumio go-librespot[4913]: time="2025-07-18T21:39:23+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 18 21:39:24 richdacvolumio go-librespot[4913]: time="2025-07-18T21:39:24+01:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.65.9:4070: connect: connection refused" Jul 18 21:39:24 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 18 21:39:24 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 18 21:39:24 richdacvolumio volumio[3782]: info: Connection to go-librespot Websocket closed Jul 18 21:39:24 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:24 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:24 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:24 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:24 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:24 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:24 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:24 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:24 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:24 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:24 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:24 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:25 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:25 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:25 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:25 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:25 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:25 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:25 richdacvolumio volumio[3782]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:25 richdacvolumio volumio[3782]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:25 richdacvolumio volumio[3782]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 18 21:39:25 richdacvolumio volumio[3782]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 18 21:39:25 richdacvolumio volumio[3782]: TypeError: Cannot read property 'length' of undefined Jul 18 21:39:25 richdacvolumio volumio[3782]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Jul 18 21:39:25 richdacvolumio volumio[3782]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Jul 18 21:39:25 richdacvolumio volumio[3782]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Jul 18 21:39:25 richdacvolumio volumio[3782]: at Parser.emit (events.js:315:20) Jul 18 21:39:25 richdacvolumio volumio[3782]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Jul 18 21:39:25 richdacvolumio volumio[3782]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Jul 18 21:39:25 richdacvolumio volumio[3782]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Jul 18 21:39:25 richdacvolumio volumio[3782]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Jul 18 21:39:25 richdacvolumio volumio[3782]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Jul 18 21:39:25 richdacvolumio volumio[3782]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Jul 18 21:39:25 richdacvolumio volumio[3782]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Jul 18 21:39:25 richdacvolumio volumio[3782]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Jul 18 21:39:25 richdacvolumio volumio[3782]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Jul 18 21:39:25 richdacvolumio volumio[3782]: at IncomingMessage.emit (events.js:327:22) Jul 18 21:39:25 richdacvolumio volumio[3782]: at endReadableNT (internal/streams/readable.js:1327:12) Jul 18 21:39:25 richdacvolumio volumio[3782]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jul 18 21:39:25 richdacvolumio volumio[3782]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 18 21:39:26 richdacvolumio sudo[5000]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-18 21:38 Jul 18 21:39:26 richdacvolumio sudo[5000]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:26 richdacvolumio sudo[5000]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:26 richdacvolumio volumio-remote-updater[683]: [2025-07-18 21:39:26] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jul 18 21:39:26 richdacvolumio volumio-remote-updater[683]: [2025-07-18 21:39:26] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jul 18 21:39:26 richdacvolumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jul 18 21:39:26 richdacvolumio sudo[3857]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:26 richdacvolumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jul 18 21:39:26 richdacvolumio systemd[1]: Started dynamicswap service. Jul 18 21:39:26 richdacvolumio systemd[1]: dynamicswap.service: Succeeded. Jul 18 21:39:26 richdacvolumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Jul 18 21:39:26 richdacvolumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2. Jul 18 21:39:26 richdacvolumio systemd[1]: Stopped Volumio Backend Module. Jul 18 21:39:26 richdacvolumio systemd[1]: Started Volumio Backend Module. Jul 18 21:39:26 richdacvolumio systemd[1]: Started dynamicswap service. Jul 18 21:39:26 richdacvolumio systemd[1]: dynamicswap.service: Succeeded. Jul 18 21:39:27 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 18 21:39:27 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jul 18 21:39:27 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jul 18 21:39:27 richdacvolumio systemd[1]: Started go-librespot Daemon. Jul 18 21:39:27 richdacvolumio go-librespot[5041]: Librespot-go daemon starting... Jul 18 21:39:27 richdacvolumio go-librespot[5041]: time="2025-07-18T21:39:27+01:00" level=info msg="generated new device id: fcf020b0f53f63fb5111e741f3d06a984b7cb190" Jul 18 21:39:27 richdacvolumio go-librespot[5041]: time="2025-07-18T21:39:27+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jul 18 21:39:27 richdacvolumio go-librespot[5041]: time="2025-07-18T21:39:27+01:00" level=debug msg="obtained new client token: AAB/wamGYj/Gmie9pLd+jIZ/1N5F4f+OKSodZ5mX5sEUD/BG4kObmsn5UJplHG4wtqv4oqgcsBwW+OGPFpZFBKj2LzSESQdZ6LgQIqvGNqkA9Wqkh7zzEiKnreWcdd0xgilzVKiy8ZYJKinMU3e2CUUW3d8JNWFXFM8Gm0LcCxgtuxTxW/EPg3gTuGKrs0kttpeU6RomLEtTu7DK1zD3Atugw0l0SI4fAUtqpgRl3ZilkELL0tF9sLX7K0PGMg==" Jul 18 21:39:27 richdacvolumio volumio[5016]: info: ------------------------------------------- Jul 18 21:39:27 richdacvolumio volumio[5016]: info: ----- Volumio3 ---- Jul 18 21:39:27 richdacvolumio volumio[5016]: info: ------------------------------------------- Jul 18 21:39:27 richdacvolumio volumio[5016]: info: ----- System startup ---- Jul 18 21:39:27 richdacvolumio volumio[5016]: info: ------------------------------------------- Jul 18 21:39:27 richdacvolumio go-librespot[5041]: time="2025-07-18T21:39:27+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jul 18 21:39:27 richdacvolumio go-librespot[5041]: time="2025-07-18T21:39:27+01:00" level=debug msg="completed keyexchange" Jul 18 21:39:28 richdacvolumio volumio[5016]: info: MYVOLUMIO Environment detected Jul 18 21:39:28 richdacvolumio volumio[5016]: info: Plugin folders cleanup Jul 18 21:39:28 richdacvolumio volumio[5016]: info: Scanning into folder /volumio/app/plugins/ Jul 18 21:39:28 richdacvolumio volumio[5016]: info: Scanning category audio_interface Jul 18 21:39:28 richdacvolumio volumio[5016]: info: Scanning category miscellanea Jul 18 21:39:28 richdacvolumio volumio[5016]: info: Scanning category music_service Jul 18 21:39:28 richdacvolumio volumio[5016]: info: Scanning category plugins.json Jul 18 21:39:28 richdacvolumio volumio[5016]: info: Scanning category system_controller Jul 18 21:39:28 richdacvolumio volumio[5016]: info: Scanning category user_interface Jul 18 21:39:28 richdacvolumio volumio[5016]: info: Scanning into folder /data/plugins/ Jul 18 21:39:28 richdacvolumio volumio[5016]: info: Scanning category audio_interface Jul 18 21:39:28 richdacvolumio volumio[5016]: info: Scanning category music_service Jul 18 21:39:28 richdacvolumio volumio[5016]: info: Scanning category system_hardware Jul 18 21:39:28 richdacvolumio volumio[5016]: info: Scanning category user_interface Jul 18 21:39:28 richdacvolumio volumio[5016]: info: Plugin folders cleanup completed Jul 18 21:39:28 richdacvolumio volumio[5016]: info: ------------------------------------------- Jul 18 21:39:28 richdacvolumio volumio[5016]: info: ----- Core plugins startup ---- Jul 18 21:39:28 richdacvolumio volumio[5016]: info: ------------------------------------------- Jul 18 21:39:28 richdacvolumio volumio[5016]: info: Loading plugins from folder /volumio/app/plugins/ Jul 18 21:39:28 richdacvolumio volumio[5016]: info: Adding plugin upnp to MyMusic Plugins Jul 18 21:39:28 richdacvolumio volumio[5016]: info: Adding plugin airplay_emulation to MyMusic Plugins Jul 18 21:39:28 richdacvolumio volumio[5016]: info: Adding plugin upnp_browser to MyMusic Plugins Jul 18 21:39:28 richdacvolumio volumio[5016]: info: Loading plugins from folder /data/plugins/ Jul 18 21:39:28 richdacvolumio volumio[5016]: info: Loading plugin "system"... Jul 18 21:39:28 richdacvolumio volumio[5016]: info: Loading plugin "appearance"... Jul 18 21:39:28 richdacvolumio go-librespot[5041]: time="2025-07-18T21:39:28+01:00" level=debug msg="completed challenge" Jul 18 21:39:28 richdacvolumio go-librespot[5041]: time="2025-07-18T21:39:28+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 18 21:39:28 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 18 21:39:28 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 18 21:39:29 richdacvolumio volumio[5016]: info: Loading plugin "network"... Jul 18 21:39:29 richdacvolumio volumio[5016]: info: Refreshing Cached IP Addresses Jul 18 21:39:29 richdacvolumio sudo[5063]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 18 21:39:29 richdacvolumio sudo[5063]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:29 richdacvolumio sudo[5065]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 18 21:39:29 richdacvolumio sudo[5065]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:29 richdacvolumio sudo[5063]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:29 richdacvolumio sudo[5065]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:29 richdacvolumio volumio[5016]: info: Loading plugin "services"... Jul 18 21:39:29 richdacvolumio volumio[5016]: info: Loading plugin "alsa_controller"... Jul 18 21:39:29 richdacvolumio sudo[5078]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jul 18 21:39:29 richdacvolumio sudo[5078]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:29 richdacvolumio volumio[5016]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 18 21:39:29 richdacvolumio volumio[5016]: info: Loading plugin "wizard"... Jul 18 21:39:29 richdacvolumio volumio[5016]: info: Loading plugin "networkfs"... Jul 18 21:39:29 richdacvolumio volumio[5016]: info: Starting Udev Watcher for removable devices Jul 18 21:39:29 richdacvolumio sudo[5091]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t nfs -o ro,soft,noauto,vers=2.1 192.168.0.89:d: /mnt/NAS/server Jul 18 21:39:29 richdacvolumio volumio[5016]: info: Ignoring mount for partition: boot Jul 18 21:39:29 richdacvolumio volumio[5016]: info: Ignoring mount for partition: volumio Jul 18 21:39:29 richdacvolumio volumio[5016]: info: Ignoring mount for partition: volumio_data Jul 18 21:39:29 richdacvolumio volumio[5016]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 18 21:39:29 richdacvolumio sudo[5091]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:29 richdacvolumio volumio[5016]: info: Loading plugin "volumio_command_line_client"... Jul 18 21:39:29 richdacvolumio volumio[5016]: info: Loading plugin "upnp"... Jul 18 21:39:29 richdacvolumio volumio[5016]: info: [1752871169552] Starting Upmpd Daemon Jul 18 21:39:29 richdacvolumio volumio[5016]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 18 21:39:29 richdacvolumio volumio[5016]: info: Loading plugin "my_music"... Jul 18 21:39:29 richdacvolumio volumio[5016]: info: Loading plugin "mpd"... Jul 18 21:39:29 richdacvolumio volumio[5016]: info: Loading plugin "upnp_browser"... Jul 18 21:39:30 richdacvolumio volumio[5016]: info: Loading plugin "alarm-clock"... Jul 18 21:39:30 richdacvolumio volumio[5016]: info: Loading plugin "airplay_emulation"... Jul 18 21:39:30 richdacvolumio volumio[5016]: info: Starting Shairport Sync Jul 18 21:39:30 richdacvolumio volumio[5016]: info: Loading plugin "last_100"... Jul 18 21:39:30 richdacvolumio volumio[5016]: info: Loading plugin "webradio"... Jul 18 21:39:30 richdacvolumio volumio[5016]: info: Loading plugin "i2s_dacs"... Jul 18 21:39:30 richdacvolumio volumio[5016]: info: Loading plugin "volumiodiscovery"... Jul 18 21:39:30 richdacvolumio volumio[5016]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jul 18 21:39:30 richdacvolumio volumio[5016]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 18 21:39:30 richdacvolumio volumio[5016]: *** WARNING *** For more information see Jul 18 21:39:30 richdacvolumio volumio[5016]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jul 18 21:39:30 richdacvolumio node[5016]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jul 18 21:39:30 richdacvolumio volumio[5016]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 18 21:39:30 richdacvolumio volumio[5016]: *** WARNING *** For more information see Jul 18 21:39:30 richdacvolumio node[5016]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 18 21:39:30 richdacvolumio node[5016]: *** WARNING *** For more information see Jul 18 21:39:30 richdacvolumio node[5016]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jul 18 21:39:30 richdacvolumio node[5016]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 18 21:39:30 richdacvolumio node[5016]: *** WARNING *** For more information see Jul 18 21:39:30 richdacvolumio volumio[5016]: info: Applying required configuration parameters for plugin volumiodiscovery Jul 18 21:39:30 richdacvolumio volumio[5016]: info: Discovery: Started advertising with name: Richdacvolumio Jul 18 21:39:30 richdacvolumio volumio[5016]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 18 21:39:30 richdacvolumio volumio[5016]: info: Loading plugin "bandcamp"... Jul 18 21:39:31 richdacvolumio volumio[5016]: info: Loading plugin "mixcloud"... Jul 18 21:39:31 richdacvolumio volumio-remote-updater[683]: [2025-07-18 21:39:31] [connect] Successful connection Jul 18 21:39:31 richdacvolumio volumio[5016]: info: Loading plugin "spop"... Jul 18 21:39:31 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 18 21:39:31 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jul 18 21:39:31 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jul 18 21:39:31 richdacvolumio systemd[1]: Started go-librespot Daemon. Jul 18 21:39:31 richdacvolumio go-librespot[5096]: Librespot-go daemon starting... Jul 18 21:39:31 richdacvolumio go-librespot[5096]: time="2025-07-18T21:39:31+01:00" level=info msg="generated new device id: 59cafe8fd9c487eb0c3deca432bdfd19722c32e0" Jul 18 21:39:31 richdacvolumio go-librespot[5096]: time="2025-07-18T21:39:31+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jul 18 21:39:32 richdacvolumio go-librespot[5096]: time="2025-07-18T21:39:32+01:00" level=debug msg="obtained new client token: AAAhPx2Id91Vi09FvEdAR5d54DloPd94w3s3WWP+iiElZ3L8Mg+ECpm0sdFf5ex6UUMyr281P7iIB1MQevAKselBgJcsFTafXKZKS5BXrm7+ZWWUJhyPeyLxoIvVq773rnzZkU8UsOcUnWAIAtcmDU6UrMOEUl+qmsOyhiLQjd30H3I1UKjrjTdHcbosi6w/PEO3u7ISHYWKsDxYIuMfW6Xt5n3Swjs/sM38rrNAN79JvWal2Phe1piarzZBjg==" Jul 18 21:39:32 richdacvolumio volumio[5016]: info: Loading plugin "youtube2"... Jul 18 21:39:33 richdacvolumio sudo[5078]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:33 richdacvolumio volumio[5016]: info: Loading plugin "ytcr"... Jul 18 21:39:34 richdacvolumio volumio[5016]: info: Loading plugin "now_playing"... Jul 18 21:39:35 richdacvolumio volumio[5016]: info: Loading plugin "outputs"... Jul 18 21:39:35 richdacvolumio volumio[5016]: info: Loading plugin "albumart"... Jul 18 21:39:35 richdacvolumio volumio[5016]: info: Plugin example_plugin is not enabled Jul 18 21:39:35 richdacvolumio volumio[5016]: info: Loading plugin "inputs"... Jul 18 21:39:35 richdacvolumio volumio[5016]: info: Loading plugin "updater_comm"... Jul 18 21:39:35 richdacvolumio volumio[5016]: info: Plugin mpdemulation is not enabled Jul 18 21:39:35 richdacvolumio volumio[5016]: info: Loading plugin "rest_api"... Jul 18 21:39:36 richdacvolumio volumio[5016]: info: Loading plugin "websocket"... Jul 18 21:39:36 richdacvolumio volumio[5016]: info: Starting Socket.io Server version 2.3.0 Jul 18 21:39:36 richdacvolumio volumio[5016]: info: Loading plugin "fusiondsp"... Jul 18 21:39:36 richdacvolumio volumio[5016]: Forking 3 albumart workers Jul 18 21:39:36 richdacvolumio volumio[5016]: info: Applying required configuration parameters for plugin fusiondsp Jul 18 21:39:36 richdacvolumio volumio[5016]: info: Loading plugin "mpdoutput"... Jul 18 21:39:36 richdacvolumio volumio[5016]: info: Loading plugin "80s80s"... Jul 18 21:39:37 richdacvolumio volumio[5016]: Starting albumart workers Jul 18 21:39:37 richdacvolumio volumio[5016]: Starting albumart workers Jul 18 21:39:37 richdacvolumio volumio[5016]: info: Applying required configuration parameters for plugin 80s80s Jul 18 21:39:37 richdacvolumio volumio[5016]: info: [1752871177212] [80s80s] API delay: 30 Jul 18 21:39:37 richdacvolumio volumio[5016]: info: Loading plugin "dmd2_music"... Jul 18 21:39:37 richdacvolumio volumio[5016]: Starting albumart workers Jul 18 21:39:38 richdacvolumio volumio[5016]: info: Loading plugin "minidlna"... Jul 18 21:39:38 richdacvolumio volumio[5016]: info: Applying required configuration parameters for plugin minidlna Jul 18 21:39:38 richdacvolumio volumio[5016]: info: Loading plugin "motherearthradio"... Jul 18 21:39:38 richdacvolumio volumio[5016]: info: Applying required configuration parameters for plugin motherearthradio Jul 18 21:39:38 richdacvolumio volumio[5016]: info: [1752871178678] [MotherEarth] API delay: 5 Jul 18 21:39:38 richdacvolumio volumio[5016]: info: Loading plugin "mpd_oled"... Jul 18 21:39:38 richdacvolumio volumio[5016]: info: Applying required configuration parameters for plugin mpd_oled Jul 18 21:39:38 richdacvolumio volumio[5016]: info: [MPD_OLED Plugin] Reading configuration file at: /data/configuration/system_hardware/mpd_oled/config.json Jul 18 21:39:38 richdacvolumio volumio[5016]: info: Loading plugin "Systeminfo"... Jul 18 21:39:39 richdacvolumio volumio[5016]: info: Loading plugin "touch_display"... Jul 18 21:39:39 richdacvolumio volumio[5016]: info: Applying required configuration parameters for plugin touch_display Jul 18 21:39:39 richdacvolumio volumio[5016]: info: Loading i18n strings for locale en Jul 18 21:39:39 richdacvolumio volumio[5016]: info: Plugin mpdoutput has duplicated i18n key SAVE. It is ignored. Jul 18 21:39:39 richdacvolumio volumio[5016]: Updating browse sources language Jul 18 21:39:39 richdacvolumio volumio[5016]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 18 21:39:39 richdacvolumio volumio[5016]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 18 21:39:39 richdacvolumio volumio[5016]: info: CoreCommandRouter::initPlayerControls Jul 18 21:39:39 richdacvolumio volumio[5016]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:39:39 richdacvolumio volumio[5016]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 18 21:39:39 richdacvolumio volumio[5016]: Express server listening on port 3000 Jul 18 21:39:39 richdacvolumio volumio[5016]: [Metrics] WebUI: 12s 91.20ms Jul 18 21:39:39 richdacvolumio volumio[5016]: info: CoreStateMachine::resetVolumioState Jul 18 21:39:39 richdacvolumio volumio[5016]: info: CoreStateMachine::getcurrentVolume Jul 18 21:39:39 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioRetrievevolume Jul 18 21:39:39 richdacvolumio sudo[5176]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 18 21:39:39 richdacvolumio sudo[5176]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:39 richdacvolumio sudo[5176]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:39 richdacvolumio sudo[5179]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 18 21:39:39 richdacvolumio sudo[5179]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:39 richdacvolumio sudo[5179]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:39 richdacvolumio volumio[5016]: info: Volumio Network Manager: Network status updated: 2 Jul 18 21:39:39 richdacvolumio volumio[5016]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Jul 18 21:39:39 richdacvolumio volumio[5016]: verbose: New Socket.io Connection to 192.168.0.106 from 192.168.0.150 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Jul 18 21:39:39 richdacvolumio volumio[5016]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Jul 18 21:39:39 richdacvolumio volumio[5016]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Jul 18 21:39:39 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:39 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:39 richdacvolumio volumio[5016]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jul 18 21:39:39 richdacvolumio volumio[5016]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Jul 18 21:39:39 richdacvolumio volumio[5016]: info: VolumeController:: Volume=100 Mute =false Jul 18 21:39:39 richdacvolumio volumio[5016]: info: CoreStateMachine::pushState Jul 18 21:39:39 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:39 richdacvolumio volumio[5016]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 21:39:39 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioPushState Jul 18 21:39:39 richdacvolumio volumio[5016]: info: CoreStateMachine::updateTrackBlock Jul 18 21:39:39 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrackBlock Jul 18 21:39:39 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioRetrievevolume Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 21:39:40 richdacvolumio volumio[5016]: info: Reloading queue from file Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetVisibleSources Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jul 18 21:39:40 richdacvolumio volumio[5016]: info: Received Get System Info Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 18 21:39:40 richdacvolumio volumio[5016]: info: Discovery: Getting this device information Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:40 richdacvolumio volumio[5016]: info: Listing playlists Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetQueue Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreStateMachine::getQueue Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CorePlayQueue::getQueue Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreStateMachine::setRepeat false single undefined Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreStateMachine::pushState Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioPushState Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreStateMachine::setRandom null Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreStateMachine::pushState Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioPushState Jul 18 21:39:40 richdacvolumio volumio[5016]: info: Setting Device type: Raspberry PI Jul 18 21:39:40 richdacvolumio volumio[5016]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Jul 18 21:39:40 richdacvolumio volumio[5016]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03115 Jul 18 21:39:40 richdacvolumio volumio[5016]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:40 richdacvolumio volumio[5016]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Jul 18 21:39:40 richdacvolumio volumio[5016]: info: VolumeController:: Volume=100 Mute =false Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreStateMachine::pushState Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioPushState Jul 18 21:39:40 richdacvolumio sudo[5196]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jul 18 21:39:40 richdacvolumio sudo[5196]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:40 richdacvolumio sudo[5196]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jul 18 21:39:40 richdacvolumio volumio[5016]: info: Upmpdcli Daemon Started Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetVisibleSources Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jul 18 21:39:40 richdacvolumio volumio[5016]: info: Received Get System Info Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 18 21:39:40 richdacvolumio volumio[5016]: info: Discovery: Getting this device information Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:40 richdacvolumio volumio[5016]: info: Listing playlists Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetQueue Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreStateMachine::getQueue Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CorePlayQueue::getQueue Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:40 richdacvolumio volumio[5016]: info: Discovery: adding 3bdb1a91-7849-4670-8b08-57856d411c7d Jul 18 21:39:40 richdacvolumio volumio[5016]: info: Discovery: Found device Richdacvolumio Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 18 21:39:40 richdacvolumio volumio[5016]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 18 21:39:41 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:41 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:41 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:41 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:41 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:41 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:41 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:41 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:42 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:42 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:42 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:42 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:42 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:42 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:42 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:42 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:42 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:42 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:42 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:42 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:42 richdacvolumio go-librespot[5096]: time="2025-07-18T21:39:42+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jul 18 21:39:42 richdacvolumio go-librespot[5096]: time="2025-07-18T21:39:42+01:00" level=debug msg="completed keyexchange" Jul 18 21:39:43 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:43 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:43 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:43 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:43 richdacvolumio go-librespot[5096]: time="2025-07-18T21:39:43+01:00" level=debug msg="completed challenge" Jul 18 21:39:43 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:43 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:43 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:43 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:43 richdacvolumio go-librespot[5096]: time="2025-07-18T21:39:43+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 18 21:39:43 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 18 21:39:43 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 18 21:39:43 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:43 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:43 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:43 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:43 richdacvolumio volumio-remote-updater[683]: [2025-07-18 21:39:43] [connect] Successful connection Jul 18 21:39:43 richdacvolumio volumio-remote-updater[683]: [2025-07-18 21:39:43] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1752871183 101 Jul 18 21:39:43 richdacvolumio volumio[5016]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 7 Jul 18 21:39:44 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:44 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:44 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:44 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:44 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:44 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:44 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:44 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:44 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:44 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:44 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:44 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:45 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:45 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:45 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:45 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:45 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:45 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:45 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:45 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:45 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:45 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:45 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:45 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:46 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:46 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:46 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:46 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:46 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:46 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:46 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:46 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:46 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 18 21:39:46 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jul 18 21:39:46 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jul 18 21:39:46 richdacvolumio systemd[1]: Started go-librespot Daemon. Jul 18 21:39:46 richdacvolumio go-librespot[5303]: Librespot-go daemon starting... Jul 18 21:39:46 richdacvolumio go-librespot[5303]: time="2025-07-18T21:39:46+01:00" level=info msg="generated new device id: 155e63eaead85998f92d4736efa2f5e6a07b403b" Jul 18 21:39:46 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:46 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:46 richdacvolumio go-librespot[5303]: time="2025-07-18T21:39:46+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jul 18 21:39:46 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:46 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:47 richdacvolumio go-librespot[5303]: time="2025-07-18T21:39:47+01:00" level=debug msg="obtained new client token: AAAjlsigcLr0bXOX6aJqQ8Qu8kvgrvHfGS7FMW4y4lKvib+uRmX2Ad30af8O1wwpeuZnwIcDBrxKV16KghNFQodR8LvgvN22Y9AcNn6UNYsegd5qsDoyxu3qFfZDtzg3Rd0XhcRqslQ1RNybCfqBz2lpMM85916VZgxzZ2eqqcpTWM0YUDeBhPPt7qXVV3pPRX5WxlU/upmKssDII2McuVs6LvLO+bPcVOO0kHZjlMboHWjfMOcKpA4wY04=" Jul 18 21:39:47 richdacvolumio go-librespot[5303]: time="2025-07-18T21:39:47+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jul 18 21:39:47 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:47 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:47 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:47 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:47 richdacvolumio go-librespot[5303]: time="2025-07-18T21:39:47+01:00" level=debug msg="completed keyexchange" Jul 18 21:39:47 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:47 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:47 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:47 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:47 richdacvolumio go-librespot[5303]: time="2025-07-18T21:39:47+01:00" level=debug msg="completed challenge" Jul 18 21:39:47 richdacvolumio go-librespot[5303]: time="2025-07-18T21:39:47+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 18 21:39:47 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 18 21:39:47 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 18 21:39:47 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:47 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:47 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:47 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:48 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:48 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:48 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:48 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:48 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:48 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:48 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:48 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:48 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:48 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:48 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:48 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:49 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:49 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:49 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:49 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:49 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:49 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:49 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:49 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:49 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:49 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:49 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:49 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:50 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:50 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:50 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:50 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:50 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:50 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:50 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:50 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:50 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:50 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:50 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:50 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:51 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 18 21:39:51 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jul 18 21:39:51 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jul 18 21:39:51 richdacvolumio systemd[1]: Started go-librespot Daemon. Jul 18 21:39:51 richdacvolumio go-librespot[5403]: Librespot-go daemon starting... Jul 18 21:39:51 richdacvolumio go-librespot[5403]: time="2025-07-18T21:39:51+01:00" level=info msg="generated new device id: b8540e74d3b240caf5af3c5aa10d6fcd9d4c6ea7" Jul 18 21:39:51 richdacvolumio go-librespot[5403]: time="2025-07-18T21:39:51+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jul 18 21:39:51 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:51 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:51 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:51 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:51 richdacvolumio go-librespot[5403]: time="2025-07-18T21:39:51+01:00" level=debug msg="obtained new client token: AADSfD/YTo7fv1LyVjzFlmrJ/iKR7Xj4ra//IpPiU2BfPhqjdD35BtpytmvrAJdIjyPIlIyIyXGknwsoxMppSM4aWsEmvj9JMzy1F9aOKtPthQwPoq6Le7ETHqO2KEEMnjlVzERIzeaMRAMbqrHqlHo9MzvQZA7ykrTAq6Yb/T3kMwZCB0y5j8gugS9A9m2Zi4hl+aawuJfg6vZDfhs+W5XtDb+96tTg+M20g+odb3AN41gDpUTsRamYNyKa+Q==" Jul 18 21:39:51 richdacvolumio go-librespot[5403]: time="2025-07-18T21:39:51+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jul 18 21:39:51 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:51 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:51 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:51 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:51 richdacvolumio go-librespot[5403]: time="2025-07-18T21:39:51+01:00" level=debug msg="completed keyexchange" Jul 18 21:39:51 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:51 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:51 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:51 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:52 richdacvolumio go-librespot[5403]: time="2025-07-18T21:39:52+01:00" level=debug msg="completed challenge" Jul 18 21:39:52 richdacvolumio go-librespot[5403]: time="2025-07-18T21:39:52+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 18 21:39:52 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 18 21:39:52 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 18 21:39:52 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:52 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:52 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:52 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:52 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:52 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:52 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:52 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:52 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:52 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:52 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:52 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:53 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:53 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:53 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:53 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:53 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:53 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:53 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:53 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:53 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:53 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:53 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:53 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:54 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:54 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:54 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:54 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:54 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:54 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:54 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:54 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:55 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:55 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:55 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:55 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:55 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 18 21:39:55 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jul 18 21:39:55 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jul 18 21:39:55 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:55 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:55 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:55 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:55 richdacvolumio systemd[1]: Started go-librespot Daemon. Jul 18 21:39:55 richdacvolumio go-librespot[5484]: Librespot-go daemon starting... Jul 18 21:39:55 richdacvolumio go-librespot[5484]: time="2025-07-18T21:39:55+01:00" level=info msg="generated new device id: 614562cead6f31df4b9db33d791f8f8312107fba" Jul 18 21:39:55 richdacvolumio go-librespot[5484]: time="2025-07-18T21:39:55+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jul 18 21:39:55 richdacvolumio go-librespot[5484]: time="2025-07-18T21:39:55+01:00" level=debug msg="obtained new client token: AADeWzFfYgEGZEaeod9xhZZd3vZPrco0MTc7uFqgPO46Mt7VycuDZ83SVwV5JchziPZ93JkhrCUWlkfA6gmm1C9fHwcxlSzmblY0BPnrK77HB2T7DB0u7sqH2TY1JPMinJszrHDTha3l8ImnSaMIGysbppHfcndDLdGhIcqslCx66Oh0wEsi7Zfw7qaoGkavbIoVyk+/QWVcDGueh1S4hQH/pn0KPGlL9U5OREP+zY+iG4Oad1opjusr1wW3Sw==" Jul 18 21:39:55 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:55 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:55 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:55 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:55 richdacvolumio go-librespot[5484]: time="2025-07-18T21:39:55+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 18 21:39:55 richdacvolumio go-librespot[5484]: time="2025-07-18T21:39:55+01:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.65.9:4070: connect: connection refused" Jul 18 21:39:55 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 18 21:39:55 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 18 21:39:56 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:56 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:56 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:56 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:56 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:56 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:56 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:56 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:56 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:56 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:56 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:56 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:57 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:57 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:57 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:57 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:57 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:57 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:57 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:57 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:57 richdacvolumio volumio[5016]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 18 21:39:57 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:57 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:57 richdacvolumio volumio[5016]: info: CoreCommandRouter::volumioGetState Jul 18 21:39:57 richdacvolumio volumio[5016]: info: CorePlayQueue::getTrack 0 Jul 18 21:39:57 richdacvolumio volumio[5016]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 18 21:39:57 richdacvolumio volumio[5016]: TypeError: Cannot read property 'length' of undefined Jul 18 21:39:57 richdacvolumio volumio[5016]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Jul 18 21:39:57 richdacvolumio volumio[5016]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Jul 18 21:39:57 richdacvolumio volumio[5016]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Jul 18 21:39:57 richdacvolumio volumio[5016]: at Parser.emit (events.js:315:20) Jul 18 21:39:57 richdacvolumio volumio[5016]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Jul 18 21:39:57 richdacvolumio volumio[5016]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Jul 18 21:39:57 richdacvolumio volumio[5016]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Jul 18 21:39:57 richdacvolumio volumio[5016]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Jul 18 21:39:57 richdacvolumio volumio[5016]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Jul 18 21:39:57 richdacvolumio volumio[5016]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Jul 18 21:39:57 richdacvolumio volumio[5016]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Jul 18 21:39:57 richdacvolumio volumio[5016]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Jul 18 21:39:57 richdacvolumio volumio[5016]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Jul 18 21:39:57 richdacvolumio volumio[5016]: at IncomingMessage.emit (events.js:327:22) Jul 18 21:39:57 richdacvolumio volumio[5016]: at endReadableNT (internal/streams/readable.js:1327:12) Jul 18 21:39:57 richdacvolumio volumio[5016]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jul 18 21:39:57 richdacvolumio volumio[5016]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 18 21:39:58 richdacvolumio sudo[5549]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-18 21:38 Jul 18 21:39:58 richdacvolumio sudo[5549]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:39:58 richdacvolumio sudo[5549]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:58 richdacvolumio volumio-remote-updater[683]: [2025-07-18 21:39:58] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jul 18 21:39:58 richdacvolumio volumio-remote-updater[683]: [2025-07-18 21:39:58] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jul 18 21:39:58 richdacvolumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jul 18 21:39:58 richdacvolumio sudo[5091]: pam_unix(sudo:session): session closed for user root Jul 18 21:39:58 richdacvolumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jul 18 21:39:58 richdacvolumio systemd[1]: Started dynamicswap service. Jul 18 21:39:58 richdacvolumio systemd[1]: dynamicswap.service: Succeeded. Jul 18 21:39:58 richdacvolumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Jul 18 21:39:58 richdacvolumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 3. Jul 18 21:39:58 richdacvolumio systemd[1]: Started dynamicswap service. Jul 18 21:39:58 richdacvolumio systemd[1]: Stopped Volumio Backend Module. Jul 18 21:39:58 richdacvolumio systemd[1]: Started Volumio Backend Module. Jul 18 21:39:58 richdacvolumio systemd[1]: dynamicswap.service: Succeeded. Jul 18 21:39:58 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 18 21:39:58 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jul 18 21:39:58 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jul 18 21:39:58 richdacvolumio systemd[1]: Started go-librespot Daemon. Jul 18 21:39:58 richdacvolumio go-librespot[5585]: Librespot-go daemon starting... Jul 18 21:39:58 richdacvolumio go-librespot[5585]: time="2025-07-18T21:39:58+01:00" level=info msg="generated new device id: e74458dddd9a45858470bddd6f3747d718cdb6e8" Jul 18 21:39:58 richdacvolumio go-librespot[5585]: time="2025-07-18T21:39:58+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jul 18 21:39:59 richdacvolumio go-librespot[5585]: time="2025-07-18T21:39:59+01:00" level=debug msg="obtained new client token: AAA9P6zIS1em9NFcBJtIGcrD/rF6kKT22UUf/PAGk4Zjyc5krLECwvv64CbEGzm6zBODKYgUOTGuDiYTwHndx/M0k5qGB3Q1m6pDy990EPqoG9AAvGZRiU16jvrOmtuPuIwbew/qYkj5sYYnWkcF9O09kScKTbg9Z+MJuPXm1guwfv8P0f0g9ikI4M0UF02C9VixyIhXb9VIMRcXEyXNPgEf/52Qf384iUbGWEsyqUbrTWTDK+fqFubz/fs=" Jul 18 21:39:59 richdacvolumio go-librespot[5585]: time="2025-07-18T21:39:59+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 18 21:39:59 richdacvolumio go-librespot[5585]: time="2025-07-18T21:39:59+01:00" level=debug msg="completed keyexchange" Jul 18 21:39:59 richdacvolumio volumio[5567]: info: ------------------------------------------- Jul 18 21:39:59 richdacvolumio volumio[5567]: info: ----- Volumio3 ---- Jul 18 21:39:59 richdacvolumio volumio[5567]: info: ------------------------------------------- Jul 18 21:39:59 richdacvolumio volumio[5567]: info: ----- System startup ---- Jul 18 21:39:59 richdacvolumio volumio[5567]: info: ------------------------------------------- Jul 18 21:39:59 richdacvolumio go-librespot[5585]: time="2025-07-18T21:39:59+01:00" level=debug msg="completed challenge" Jul 18 21:39:59 richdacvolumio go-librespot[5585]: time="2025-07-18T21:39:59+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 18 21:40:00 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 18 21:40:00 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 18 21:40:00 richdacvolumio volumio[5567]: info: MYVOLUMIO Environment detected Jul 18 21:40:00 richdacvolumio volumio[5567]: info: Plugin folders cleanup Jul 18 21:40:00 richdacvolumio volumio[5567]: info: Scanning into folder /volumio/app/plugins/ Jul 18 21:40:00 richdacvolumio volumio[5567]: info: Scanning category audio_interface Jul 18 21:40:00 richdacvolumio volumio[5567]: info: Scanning category miscellanea Jul 18 21:40:00 richdacvolumio volumio[5567]: info: Scanning category music_service Jul 18 21:40:00 richdacvolumio volumio[5567]: info: Scanning category plugins.json Jul 18 21:40:00 richdacvolumio volumio[5567]: info: Scanning category system_controller Jul 18 21:40:00 richdacvolumio volumio[5567]: info: Scanning category user_interface Jul 18 21:40:00 richdacvolumio volumio[5567]: info: Scanning into folder /data/plugins/ Jul 18 21:40:00 richdacvolumio volumio[5567]: info: Scanning category audio_interface Jul 18 21:40:00 richdacvolumio volumio[5567]: info: Scanning category music_service Jul 18 21:40:00 richdacvolumio volumio[5567]: info: Scanning category system_hardware Jul 18 21:40:00 richdacvolumio volumio[5567]: info: Scanning category user_interface Jul 18 21:40:00 richdacvolumio volumio[5567]: info: Plugin folders cleanup completed Jul 18 21:40:00 richdacvolumio volumio[5567]: info: ------------------------------------------- Jul 18 21:40:00 richdacvolumio volumio[5567]: info: ----- Core plugins startup ---- Jul 18 21:40:00 richdacvolumio volumio[5567]: info: ------------------------------------------- Jul 18 21:40:00 richdacvolumio volumio[5567]: info: Loading plugins from folder /volumio/app/plugins/ Jul 18 21:40:00 richdacvolumio volumio[5567]: info: Adding plugin upnp to MyMusic Plugins Jul 18 21:40:00 richdacvolumio volumio[5567]: info: Adding plugin airplay_emulation to MyMusic Plugins Jul 18 21:40:00 richdacvolumio volumio[5567]: info: Adding plugin upnp_browser to MyMusic Plugins Jul 18 21:40:00 richdacvolumio volumio[5567]: info: Loading plugins from folder /data/plugins/ Jul 18 21:40:00 richdacvolumio volumio[5567]: info: Loading plugin "system"... Jul 18 21:40:00 richdacvolumio volumio[5567]: info: Loading plugin "appearance"... Jul 18 21:40:01 richdacvolumio volumio[5567]: info: Loading plugin "network"... Jul 18 21:40:01 richdacvolumio volumio[5567]: info: Refreshing Cached IP Addresses Jul 18 21:40:01 richdacvolumio sudo[5660]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 18 21:40:01 richdacvolumio sudo[5660]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:40:01 richdacvolumio sudo[5660]: pam_unix(sudo:session): session closed for user root Jul 18 21:40:01 richdacvolumio sudo[5662]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 18 21:40:01 richdacvolumio sudo[5662]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:40:01 richdacvolumio sudo[5662]: pam_unix(sudo:session): session closed for user root Jul 18 21:40:01 richdacvolumio volumio[5567]: info: Loading plugin "services"... Jul 18 21:40:01 richdacvolumio volumio[5567]: info: Loading plugin "alsa_controller"... Jul 18 21:40:01 richdacvolumio sudo[5671]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jul 18 21:40:01 richdacvolumio sudo[5671]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:40:01 richdacvolumio volumio[5567]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 18 21:40:01 richdacvolumio volumio[5567]: info: Loading plugin "wizard"... Jul 18 21:40:01 richdacvolumio volumio[5567]: info: Loading plugin "networkfs"... Jul 18 21:40:01 richdacvolumio volumio[5567]: info: Starting Udev Watcher for removable devices Jul 18 21:40:01 richdacvolumio sudo[5688]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t nfs -o ro,soft,noauto,vers=2.1 192.168.0.89:d: /mnt/NAS/server Jul 18 21:40:01 richdacvolumio sudo[5688]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:40:01 richdacvolumio volumio[5567]: info: Ignoring mount for partition: boot Jul 18 21:40:01 richdacvolumio volumio[5567]: info: Ignoring mount for partition: volumio Jul 18 21:40:01 richdacvolumio volumio[5567]: info: Ignoring mount for partition: volumio_data Jul 18 21:40:01 richdacvolumio volumio[5567]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 18 21:40:01 richdacvolumio volumio[5567]: info: Loading plugin "volumio_command_line_client"... Jul 18 21:40:01 richdacvolumio volumio[5567]: info: Loading plugin "upnp"... Jul 18 21:40:01 richdacvolumio volumio[5567]: info: [1752871201699] Starting Upmpd Daemon Jul 18 21:40:01 richdacvolumio volumio[5567]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 18 21:40:01 richdacvolumio volumio[5567]: info: Loading plugin "my_music"... Jul 18 21:40:01 richdacvolumio volumio[5567]: info: Loading plugin "mpd"... Jul 18 21:40:01 richdacvolumio volumio[5567]: info: Loading plugin "upnp_browser"... Jul 18 21:40:02 richdacvolumio volumio[5567]: info: Loading plugin "alarm-clock"... Jul 18 21:40:02 richdacvolumio volumio[5567]: info: Loading plugin "airplay_emulation"... Jul 18 21:40:02 richdacvolumio volumio[5567]: info: Starting Shairport Sync Jul 18 21:40:02 richdacvolumio volumio[5567]: info: Loading plugin "last_100"... Jul 18 21:40:02 richdacvolumio volumio[5567]: info: Loading plugin "webradio"... Jul 18 21:40:02 richdacvolumio volumio[5567]: info: Loading plugin "i2s_dacs"... Jul 18 21:40:02 richdacvolumio volumio[5567]: info: Loading plugin "volumiodiscovery"... Jul 18 21:40:02 richdacvolumio volumio[5567]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jul 18 21:40:02 richdacvolumio volumio[5567]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 18 21:40:02 richdacvolumio volumio[5567]: *** WARNING *** For more information see Jul 18 21:40:02 richdacvolumio node[5567]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jul 18 21:40:02 richdacvolumio volumio[5567]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jul 18 21:40:02 richdacvolumio volumio[5567]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 18 21:40:02 richdacvolumio volumio[5567]: *** WARNING *** For more information see Jul 18 21:40:02 richdacvolumio node[5567]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 18 21:40:02 richdacvolumio node[5567]: *** WARNING *** For more information see Jul 18 21:40:02 richdacvolumio node[5567]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jul 18 21:40:02 richdacvolumio node[5567]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 18 21:40:02 richdacvolumio node[5567]: *** WARNING *** For more information see Jul 18 21:40:02 richdacvolumio volumio[5567]: info: Applying required configuration parameters for plugin volumiodiscovery Jul 18 21:40:02 richdacvolumio volumio[5567]: info: Discovery: Started advertising with name: Richdacvolumio Jul 18 21:40:02 richdacvolumio volumio[5567]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 18 21:40:02 richdacvolumio volumio[5567]: info: Loading plugin "bandcamp"... Jul 18 21:40:03 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 18 21:40:03 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jul 18 21:40:03 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jul 18 21:40:03 richdacvolumio systemd[1]: Started go-librespot Daemon. Jul 18 21:40:03 richdacvolumio go-librespot[5693]: Librespot-go daemon starting... Jul 18 21:40:03 richdacvolumio go-librespot[5693]: time="2025-07-18T21:40:03+01:00" level=info msg="generated new device id: 4848cd29c8389ce006b2728034c8650e51d0aae0" Jul 18 21:40:03 richdacvolumio go-librespot[5693]: time="2025-07-18T21:40:03+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jul 18 21:40:03 richdacvolumio volumio-remote-updater[683]: [2025-07-18 21:40:03] [connect] Successful connection Jul 18 21:40:03 richdacvolumio volumio[5567]: info: Loading plugin "mixcloud"... Jul 18 21:40:03 richdacvolumio volumio[5567]: info: Loading plugin "spop"... Jul 18 21:40:04 richdacvolumio volumio[5567]: info: Loading plugin "youtube2"... Jul 18 21:40:05 richdacvolumio sudo[5671]: pam_unix(sudo:session): session closed for user root Jul 18 21:40:05 richdacvolumio volumio[5567]: info: Loading plugin "ytcr"... Jul 18 21:40:07 richdacvolumio volumio[5567]: info: Loading plugin "now_playing"... Jul 18 21:40:07 richdacvolumio volumio[5567]: info: Loading plugin "outputs"... Jul 18 21:40:07 richdacvolumio volumio[5567]: info: Loading plugin "albumart"... Jul 18 21:40:07 richdacvolumio volumio[5567]: info: Plugin example_plugin is not enabled Jul 18 21:40:07 richdacvolumio volumio[5567]: info: Loading plugin "inputs"... Jul 18 21:40:07 richdacvolumio volumio[5567]: info: Loading plugin "updater_comm"... Jul 18 21:40:08 richdacvolumio volumio[5567]: info: Plugin mpdemulation is not enabled Jul 18 21:40:08 richdacvolumio volumio[5567]: info: Loading plugin "rest_api"... Jul 18 21:40:08 richdacvolumio volumio[5567]: info: Loading plugin "websocket"... Jul 18 21:40:08 richdacvolumio volumio[5567]: info: Starting Socket.io Server version 2.3.0 Jul 18 21:40:08 richdacvolumio volumio[5567]: info: Loading plugin "fusiondsp"... Jul 18 21:40:08 richdacvolumio volumio[5567]: Forking 3 albumart workers Jul 18 21:40:08 richdacvolumio volumio[5567]: info: Applying required configuration parameters for plugin fusiondsp Jul 18 21:40:08 richdacvolumio volumio[5567]: info: Loading plugin "mpdoutput"... Jul 18 21:40:08 richdacvolumio go-librespot[5693]: time="2025-07-18T21:40:08+01:00" level=debug msg="obtained new client token: AACqIDpbh70Nkgj9E1gOHTXarTr6n1r8iLfF1pM+si0848D3HIdrfweLxduOoc3OA4pn0ZiMWfoCXyb2BUlgCEQzUQm2cYEbhdoT1NF8q1QbhdmrX5V4GHth21EwgbDyPrc201e/PrOdHEUNKqgvWP58yX8phHvZUZLkKOoQFgZsPZjfIoGi+8LKFUWC/hiGQKyU1ZXjdOOSSa3T47f+fbNMx6E0zVNRw2Yt2f+3F9WtfX0TsuzhklLsE8EyAw==" Jul 18 21:40:08 richdacvolumio go-librespot[5693]: time="2025-07-18T21:40:08+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jul 18 21:40:09 richdacvolumio volumio[5567]: info: Loading plugin "80s80s"... Jul 18 21:40:09 richdacvolumio go-librespot[5693]: time="2025-07-18T21:40:09+01:00" level=debug msg="completed keyexchange" Jul 18 21:40:09 richdacvolumio volumio[5567]: info: Applying required configuration parameters for plugin 80s80s Jul 18 21:40:09 richdacvolumio volumio[5567]: info: [1752871209377] [80s80s] API delay: 30 Jul 18 21:40:09 richdacvolumio volumio[5567]: info: Loading plugin "dmd2_music"... Jul 18 21:40:09 richdacvolumio volumio[5567]: Starting albumart workers Jul 18 21:40:09 richdacvolumio volumio[5567]: Starting albumart workers Jul 18 21:40:09 richdacvolumio volumio[5567]: Starting albumart workers Jul 18 21:40:09 richdacvolumio go-librespot[5693]: time="2025-07-18T21:40:09+01:00" level=debug msg="completed challenge" Jul 18 21:40:09 richdacvolumio go-librespot[5693]: time="2025-07-18T21:40:09+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jul 18 21:40:09 richdacvolumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 18 21:40:09 richdacvolumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 18 21:40:10 richdacvolumio volumio[5567]: info: Loading plugin "minidlna"... Jul 18 21:40:10 richdacvolumio volumio[5567]: info: Applying required configuration parameters for plugin minidlna Jul 18 21:40:10 richdacvolumio volumio[5567]: info: Loading plugin "motherearthradio"... Jul 18 21:40:10 richdacvolumio volumio[5567]: info: Applying required configuration parameters for plugin motherearthradio Jul 18 21:40:10 richdacvolumio volumio[5567]: info: [1752871210758] [MotherEarth] API delay: 5 Jul 18 21:40:10 richdacvolumio volumio[5567]: info: Loading plugin "mpd_oled"... Jul 18 21:40:10 richdacvolumio volumio[5567]: info: Applying required configuration parameters for plugin mpd_oled Jul 18 21:40:10 richdacvolumio volumio[5567]: info: [MPD_OLED Plugin] Reading configuration file at: /data/configuration/system_hardware/mpd_oled/config.json Jul 18 21:40:10 richdacvolumio volumio[5567]: info: Loading plugin "Systeminfo"... Jul 18 21:40:11 richdacvolumio volumio[5567]: info: Loading plugin "touch_display"... Jul 18 21:40:11 richdacvolumio volumio[5567]: info: Applying required configuration parameters for plugin touch_display Jul 18 21:40:11 richdacvolumio volumio[5567]: info: Loading i18n strings for locale en Jul 18 21:40:11 richdacvolumio volumio[5567]: info: Plugin mpdoutput has duplicated i18n key SAVE. It is ignored. Jul 18 21:40:11 richdacvolumio volumio[5567]: Updating browse sources language Jul 18 21:40:11 richdacvolumio volumio[5567]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 18 21:40:11 richdacvolumio volumio[5567]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 18 21:40:11 richdacvolumio volumio[5567]: info: CoreCommandRouter::initPlayerControls Jul 18 21:40:11 richdacvolumio volumio[5567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:40:11 richdacvolumio volumio[5567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 18 21:40:11 richdacvolumio volumio[5567]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 18 21:40:11 richdacvolumio volumio[5567]: Express server listening on port 3000 Jul 18 21:40:11 richdacvolumio volumio[5567]: [Metrics] WebUI: 12s 127.79ms Jul 18 21:40:11 richdacvolumio volumio[5567]: info: CoreStateMachine::resetVolumioState Jul 18 21:40:11 richdacvolumio volumio[5567]: info: CoreStateMachine::getcurrentVolume Jul 18 21:40:11 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioRetrievevolume Jul 18 21:40:11 richdacvolumio sudo[5775]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 18 21:40:11 richdacvolumio sudo[5775]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:40:11 richdacvolumio sudo[5775]: pam_unix(sudo:session): session closed for user root Jul 18 21:40:11 richdacvolumio sudo[5778]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 18 21:40:11 richdacvolumio sudo[5778]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:40:11 richdacvolumio sudo[5778]: pam_unix(sudo:session): session closed for user root Jul 18 21:40:11 richdacvolumio volumio[5567]: info: Volumio Network Manager: Network status updated: 2 Jul 18 21:40:11 richdacvolumio volumio[5567]: verbose: New Socket.io Connection to 192.168.0.106 from 192.168.0.150 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Jul 18 21:40:11 richdacvolumio volumio[5567]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Jul 18 21:40:11 richdacvolumio volumio[5567]: verbose: New Socket.io Connection to 192.168.0.106 from 192.168.0.150 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Jul 18 21:40:11 richdacvolumio volumio[5567]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Jul 18 21:40:11 richdacvolumio volumio[5567]: verbose: New Socket.io Connection to 192.168.0.106 from 192.168.0.150 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Jul 18 21:40:11 richdacvolumio volumio[5567]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioGetState Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:12 richdacvolumio volumio[5567]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jul 18 21:40:12 richdacvolumio volumio[5567]: info: VolumeController:: Volume=100 Mute =false Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CoreStateMachine::pushState Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioPushState Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CoreStateMachine::updateTrackBlock Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrackBlock Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioRetrievevolume Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 18 21:40:12 richdacvolumio volumio[5567]: info: Reloading queue from file Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CoreStateMachine::setRepeat false single undefined Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CoreStateMachine::pushState Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioPushState Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CoreStateMachine::setRandom null Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CoreStateMachine::pushState Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioPushState Jul 18 21:40:12 richdacvolumio volumio[5567]: info: Setting Device type: Raspberry PI Jul 18 21:40:12 richdacvolumio volumio[5567]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Jul 18 21:40:12 richdacvolumio volumio[5567]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03115 Jul 18 21:40:12 richdacvolumio volumio[5567]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioGetState Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:12 richdacvolumio volumio[5567]: info: VolumeController:: Volume=100 Mute =false Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CoreStateMachine::pushState Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioPushState Jul 18 21:40:12 richdacvolumio sudo[5795]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jul 18 21:40:12 richdacvolumio sudo[5795]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 18 21:40:12 richdacvolumio sudo[5795]: pam_unix(sudo:session): session closed for user root Jul 18 21:40:12 richdacvolumio volumio[5567]: info: Upmpdcli Daemon Started Jul 18 21:40:12 richdacvolumio volumio[5567]: info: Discovery: adding 3bdb1a91-7849-4670-8b08-57856d411c7d Jul 18 21:40:12 richdacvolumio volumio[5567]: info: Discovery: Found device Richdacvolumio Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioGetState Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioGetState Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioGetState Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioGetState Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioGetState Jul 18 21:40:12 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:13 richdacvolumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 18 21:40:13 richdacvolumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jul 18 21:40:13 richdacvolumio systemd[1]: Stopped go-librespot Daemon. Jul 18 21:40:13 richdacvolumio systemd[1]: Started go-librespot Daemon. Jul 18 21:40:13 richdacvolumio go-librespot[5809]: Librespot-go daemon starting... Jul 18 21:40:13 richdacvolumio go-librespot[5809]: time="2025-07-18T21:40:13+01:00" level=info msg="generated new device id: dcf8b7454d92551afcd88f8881b6d8fc21e571e8" Jul 18 21:40:13 richdacvolumio go-librespot[5809]: time="2025-07-18T21:40:13+01:00" level=debug msg="stored credentials found for eviesdaddythemainman" Jul 18 21:40:13 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioGetState Jul 18 21:40:13 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:13 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioGetState Jul 18 21:40:13 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:13 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioGetState Jul 18 21:40:13 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:13 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioGetState Jul 18 21:40:13 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:14 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioGetState Jul 18 21:40:14 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:14 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioGetState Jul 18 21:40:14 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:14 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioGetState Jul 18 21:40:14 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:14 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioGetState Jul 18 21:40:14 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:14 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioGetState Jul 18 21:40:14 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:14 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioGetState Jul 18 21:40:14 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:15 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioGetState Jul 18 21:40:15 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:15 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioGetState Jul 18 21:40:15 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:15 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioGetState Jul 18 21:40:15 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:15 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioGetState Jul 18 21:40:15 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:15 richdacvolumio volumio-remote-updater[683]: [2025-07-18 21:40:15] [connect] Successful connection Jul 18 21:40:15 richdacvolumio volumio-remote-updater[683]: [2025-07-18 21:40:15] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1752871215 101 Jul 18 21:40:15 richdacvolumio volumio[5567]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 8 Jul 18 21:40:15 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioGetState Jul 18 21:40:15 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:15 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioGetState Jul 18 21:40:15 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:16 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioGetState Jul 18 21:40:16 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:16 richdacvolumio volumio[5567]: info: CoreCommandRouter::volumioGetState Jul 18 21:40:16 richdacvolumio volumio[5567]: info: CorePlayQueue::getTrack 0 Jul 18 21:40:16 richdacvolumio volumio[5567]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Jul 18 21:40:16 richdacvolumio volumio[5567]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb Jul 18 21:40:16 richdacvolumio volumio[5567]: verbose: ControllerMpd::sendMpdCommand update Jul 18 21:40:16 richdacvolumio volumio[5567]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 18 21:40:16 richdacvolumio volumio[5567]: TypeError: Cannot read property 'then' of undefined Jul 18 21:40:16 richdacvolumio volumio[5567]: at ControllerMpd.sendMpdCommand (/volumio/app/plugins/music_service/mpd/index.js:332:6) Jul 18 21:40:16 richdacvolumio volumio[5567]: at ControllerMpd.updateDb (/volumio/app/plugins/music_service/mpd/index.js:1899:15) Jul 18 21:40:16 richdacvolumio volumio[5567]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1096:32) Jul 18 21:40:16 richdacvolumio volumio[5567]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1091:26) Jul 18 21:40:16 richdacvolumio volumio[5567]: at Socket.emit (events.js:315:20) Jul 18 21:40:16 richdacvolumio volumio[5567]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Jul 18 21:40:16 richdacvolumio volumio[5567]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Jul 18 21:40:16 richdacvolumio volumio[5567]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 18 21:40:16 richdacvolumio sudo[5880]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-18 21:39 Jul 18 21:40:16 richdacvolumio sudo[5880]: 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="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 10 Jun 2025 04:52:53 PM CEST" VOLUMIO_VERSION="3.816" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="a72866a0de4045751d03a035de6290e1"