-- Logs begin at Thu 2019-02-14 10:11:59 UTC, end at Thu 2024-03-28 19:04:42 UTC. -- Mar 28 19:03:02 volumio wpa_supplicant[742]: RRM: Ignoring radio measurement request: Not RRM network Mar 28 19:03:05 volumio volumio[814]: error: Plugin system_controller system failed to complete 'onVolumioStart' in a timely fashion Mar 28 19:03:05 volumio volumio[814]: info: Preparing to generate the ALSA configuration file Mar 28 19:03:05 volumio volumio[814]: info: The plugin peppy_screensaver has an ALSA contribution file Peppyalsa.postPeppyalsa.5.conf Mar 28 19:03:05 volumio volumio[814]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Mar 28 19:03:05 volumio volumio[814]: info: Reading ALSA contributions from plugins. Mar 28 19:03:05 volumio volumio[814]: info: Asound.conf file unchanged, so no further update is needed Mar 28 19:03:05 volumio volumio[814]: info: Output device has changed, restarting MPD Mar 28 19:03:05 volumio sudo[986]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 28 19:03:05 volumio sudo[986]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:05 volumio volumio[814]: info: Output device has changed, restarting Shairport Sync Mar 28 19:03:05 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:05 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:05 volumio sudo[986]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:05 volumio sudo[989]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 28 19:03:05 volumio sudo[989]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:05 volumio volumio[814]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 19:03:05 volumio volumio[814]: info: ___________ START PLUGINS ___________ Mar 28 19:03:05 volumio volumio[814]: info: Loading i18n strings for locale es Mar 28 19:03:05 volumio volumio[814]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Mar 28 19:03:05 volumio systemd[1]: Listening on mpd.socket. Mar 28 19:03:05 volumio systemd[1]: Starting Music Player Daemon... Mar 28 19:03:05 volumio volumio[814]: info: /tmp/myfifo created Mar 28 19:03:05 volumio sudo[999]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/modprobe snd-dummy index=7 pcm_substreams=1 Mar 28 19:03:05 volumio sudo[999]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:06 volumio sudo[999]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:06 volumio volumio[814]: info: snd-dummy loaded Mar 28 19:03:06 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:06 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:06 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:06 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Mar 28 19:03:06 volumio volumio[814]: info: ControllerMpd::onStart: Initializing MPD Mar 28 19:03:06 volumio volumio[814]: info: Creating MPD Configuration file Mar 28 19:03:06 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 28 19:03:06 volumio volumio[814]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 19:03:06 volumio volumio[814]: info: [1711652586193] CoreMusicLibrary::Adding element Media Servers Mar 28 19:03:06 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 19:03:06 volumio sudo[1010]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount --bind /data/configuration/miscellanea/peppy_screensaver/mpd.conf.tmpl /volumio/app/plugins/music_service/mpd/mpd.conf.tmpl Mar 28 19:03:06 volumio sudo[1011]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 28 19:03:06 volumio sudo[1010]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:06 volumio sudo[1011]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:06 volumio sudo[1013]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 28 19:03:06 volumio sudo[1013]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:06 volumio sudo[1011]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:06 volumio sudo[1010]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:06 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:06 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:06 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Mar 28 19:03:06 volumio systemd[1]: mpd.service: Succeeded. Mar 28 19:03:06 volumio systemd[1]: Stopped Music Player Daemon. Mar 28 19:03:06 volumio volumio[814]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 19:03:06 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:06 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:06 volumio systemd[1]: Starting Music Player Daemon... Mar 28 19:03:06 volumio volumio[814]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 19:03:06 volumio volumio[814]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 19:03:06 volumio volumio[814]: info: [1711652586523] CoreMusicLibrary::Adding element Last_100 Mar 28 19:03:06 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 19:03:06 volumio volumio[814]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 19:03:06 volumio volumio[814]: info: [1711652586532] CoreMusicLibrary::Adding element Webradio Mar 28 19:03:06 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 19:03:06 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 28 19:03:06 volumio volumio[814]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 19:03:06 volumio volumio[814]: info: [1711652586582] CoreMusicLibrary::Adding element Bandcamp Discover Mar 28 19:03:06 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 19:03:06 volumio volumio[814]: Cannot find translation for source Bandcamp Discover Mar 28 19:03:06 volumio volumio[814]: info: Creating Spotify config file Mar 28 19:03:06 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:06 volumio volumio[814]: info: AutoStart - onStart Mar 28 19:03:06 volumio volumio[814]: info: [now-playing-config] Config is up to date. Mar 28 19:03:06 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 28 19:03:06 volumio volumio[814]: info: Discovery: Getting this device information Mar 28 19:03:06 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Mar 28 19:03:06 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:06 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 28 19:03:06 volumio volumio[814]: info: Loading i18n strings for locale es Mar 28 19:03:06 volumio volumio[814]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Mar 28 19:03:06 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Mar 28 19:03:06 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:06 volumio volumio[814]: info: FusionDsp - mixtype--------------------- Hardware Mar 28 19:03:06 volumio volumio[814]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 19:03:06 volumio volumio[814]: info: [1711652586943] CoreMusicLibrary::Adding element 80s80s Radio Mar 28 19:03:06 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 19:03:06 volumio volumio[814]: Cannot find translation for source Bandcamp Discover Mar 28 19:03:06 volumio volumio[814]: Cannot find translation for source 80s80s Radio Mar 28 19:03:06 volumio volumio[814]: info: Adding Calm Radio to Browse Sources Mar 28 19:03:06 volumio volumio[814]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 19:03:06 volumio volumio[814]: info: [1711652586956] CoreMusicLibrary::Adding element Calm Radio Mar 28 19:03:06 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 19:03:06 volumio volumio[814]: Cannot find translation for source Bandcamp Discover Mar 28 19:03:06 volumio volumio[814]: Cannot find translation for source 80s80s Radio Mar 28 19:03:06 volumio volumio[814]: Cannot find translation for source Calm Radio Mar 28 19:03:06 volumio volumio[814]: info: Stopping AccessToken refresher cron for Hotel Radio Mar 28 19:03:07 volumio volumio[814]: info: AccessToken refresher cron started for Hotel Radio Mar 28 19:03:07 volumio volumio[814]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 19:03:07 volumio volumio[814]: info: [1711652587083] CoreMusicLibrary::Adding element Mother Earth Radio Mar 28 19:03:07 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 19:03:07 volumio volumio[814]: Cannot find translation for source Bandcamp Discover Mar 28 19:03:07 volumio volumio[814]: Cannot find translation for source 80s80s Radio Mar 28 19:03:07 volumio volumio[814]: Cannot find translation for source Calm Radio Mar 28 19:03:07 volumio volumio[814]: Cannot find translation for source Mother Earth Radio Mar 28 19:03:07 volumio volumio[814]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 19:03:07 volumio volumio[814]: info: [1711652587136] CoreMusicLibrary::Adding element Podcast Mar 28 19:03:07 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 19:03:07 volumio volumio[814]: Cannot find translation for source Bandcamp Discover Mar 28 19:03:07 volumio volumio[814]: Cannot find translation for source 80s80s Radio Mar 28 19:03:07 volumio volumio[814]: Cannot find translation for source Calm Radio Mar 28 19:03:07 volumio volumio[814]: Cannot find translation for source Mother Earth Radio Mar 28 19:03:07 volumio volumio[814]: Cannot find translation for source Podcast Mar 28 19:03:07 volumio volumio[814]: info: Loading i18n strings for locale es Mar 28 19:03:07 volumio volumio[814]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Mar 28 19:03:07 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 28 19:03:07 volumio volumio[814]: info: Volumio Calling Home Mar 28 19:03:07 volumio volumio[814]: info: Preparing to generate the ALSA configuration file Mar 28 19:03:07 volumio volumio[814]: info: [now-playing-app] App is listening on port 4004. Mar 28 19:03:07 volumio sudo[1028]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Mar 28 19:03:07 volumio sudo[1028]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:07 volumio systemd[1]: Reloading. Mar 28 19:03:07 volumio volumio[814]: info: The plugin peppy_screensaver has an ALSA contribution file Peppyalsa.postPeppyalsa.5.conf Mar 28 19:03:07 volumio volumio[814]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Mar 28 19:03:07 volumio volumio[814]: info: Reading ALSA contributions from plugins. Mar 28 19:03:07 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Mar 28 19:03:07 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:07 volumio volumio[814]: info: MPD Permissions set Mar 28 19:03:07 volumio volumio[814]: info: MPD Permissions set Mar 28 19:03:07 volumio volumio[814]: info: Spotify config file written Mar 28 19:03:08 volumio volumio[814]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 14 Mar 28 19:03:08 volumio volumio[814]: info: Volumio called home Mar 28 19:03:08 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:08 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:08 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:08 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:08 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:08 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:08 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:08 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:08 volumio sudo[1044]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 28 19:03:08 volumio sudo[1044]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:08 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:08 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:08 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:08 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:08 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:08 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:08 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:08 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:08 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:08 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:08 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:08 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:08 volumio volumio[814]: info: touch_display: No Raspberry Pi Foundation touch screen detected. Mar 28 19:03:08 volumio 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. Mar 28 19:03:08 volumio volumio[814]: info: Starting Shairport Sync Mar 28 19:03:08 volumio volumio[814]: info: Starting Shairport Sync Mar 28 19:03:08 volumio sudo[1055]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 19:03:08 volumio sudo[1055]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:08 volumio volumio[814]: info: Starting Shairport Sync Mar 28 19:03:08 volumio sudo[1059]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 19:03:08 volumio sudo[1060]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 19:03:08 volumio sudo[1060]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:08 volumio sudo[1059]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:08 volumio volumio[814]: info: Asound.conf file unchanged, so no further update is needed Mar 28 19:03:08 volumio volumio[814]: info: Output device has changed, restarting MPD Mar 28 19:03:08 volumio volumio[814]: info: Output device has changed, restarting Shairport Sync Mar 28 19:03:08 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:08 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:08 volumio sudo[1064]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 28 19:03:08 volumio sudo[1064]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:08 volumio sudo[1064]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:08 volumio sudo[1067]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 28 19:03:08 volumio sudo[1067]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:09 volumio volumio[814]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 19:03:09 volumio volumio[814]: info: Preparing to generate the ALSA configuration file Mar 28 19:03:09 volumio systemd[1]: getty@tty1.service: Current command vanished from the unit file, execution of the command list won't be resumed. Mar 28 19:03:09 volumio volumio[814]: info: camilladsp spawned new process with pid 1078, instance 1, run: true Mar 28 19:03:09 volumio volumio[814]: info: camilladsp service started and running in background, instance 1 Mar 28 19:03:09 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:09 volumio volumio[814]: info: FusionDsp - AAAAAAAAAAAAAA-> 44100 48000 <-AAAAAAAAAAAAA Mar 28 19:03:09 volumio volumio[814]: info: FusionDsp loaded Mar 28 19:03:09 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 28 19:03:09 volumio sudo[1084]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Mar 28 19:03:09 volumio sudo[1084]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:09 volumio volumio[814]: info: FusionDsp - Reporting Fusion DSP Enabled Mar 28 19:03:09 volumio volumio[814]: info: Adding Signal Path Element [object Object] Mar 28 19:03:09 volumio volumio[814]: info: Adding fusiondspeq DSP Signal Path Element Mar 28 19:03:09 volumio volumio[814]: info: FusionDsp - ---- installed callbackRead Mar 28 19:03:09 volumio sudo[1028]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:09 volumio volumio[814]: info: FusionDsp - If filter freq >samplerate/2 then disable it Mar 28 19:03:09 volumio volumio[814]: info: The plugin peppy_screensaver has an ALSA contribution file Peppyalsa.postPeppyalsa.5.conf Mar 28 19:03:09 volumio volumio[814]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Mar 28 19:03:09 volumio volumio[814]: info: Reading ALSA contributions from plugins. Mar 28 19:03:09 volumio volumio[814]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Mar 28 19:03:09 volumio volumio[814]: SPOTIFY: BQDuk7rnSfjpN9yU2WXg1miPILvlLd34uQAnjw3jqkjhKeSCdWYH9uEQpG932yYVbpvWd7lZyX-LeFenXoENrIxmtzgOLNflomlpjqJOGlW20poZnrlxBaHwVLvmZ0iD3hTxPbnLz7Y_-T-RKeZmx9of31_Nr9lLCj2QcR4NW3sGisgP24DV1f-mBO0Me95ctBJZGWWry6i9jXRtRx51__CdwM6jmaw1jUPBM_mblOG_EBSyDAKp Mar 28 19:03:09 volumio volumio[814]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Mar 28 19:03:09 volumio volumio[814]: info: New Spotify access token = BQDuk7rnSfjpN9yU2WXg1miPILvlLd34uQAnjw3jqkjhKeSCdWYH9uEQpG932yYVbpvWd7lZyX-LeFenXoENrIxmtzgOLNflomlpjqJOGlW20poZnrlxBaHwVLvmZ0iD3hTxPbnLz7Y_-T-RKeZmx9of31_Nr9lLCj2QcR4NW3sGisgP24DV1f-mBO0Me95ctBJZGWWry6i9jXRtRx51__CdwM6jmaw1jUPBM_mblOG_EBSyDAKp Mar 28 19:03:09 volumio volumio[814]: info: Spotify credentials grant success - running version from March 24, 2019 Mar 28 19:03:09 volumio volumio[814]: info: MPD Permissions set Mar 28 19:03:09 volumio volumio[814]: info: touch_display: systemctl daemon-reload succeeded. Mar 28 19:03:09 volumio systemd[1]: Started FusionDsp Daemon. Mar 28 19:03:09 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:09 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:09 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 28 19:03:09 volumio systemd[1]: Started go-librespot Daemon. Mar 28 19:03:09 volumio sudo[1093]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Mar 28 19:03:09 volumio sudo[1093]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:09 volumio go-librespot[1094]: Librespot-go daemon starting... Mar 28 19:03:09 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Mar 28 19:03:09 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:09 volumio sudo[1044]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:09 volumio systemd[1]: shairport-sync.service: Succeeded. Mar 28 19:03:09 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 28 19:03:09 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Mar 28 19:03:09 volumio systemd[1]: mpd.service: Succeeded. Mar 28 19:03:09 volumio systemd[1]: Stopped Music Player Daemon. Mar 28 19:03:10 volumio sudo[1084]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:10 volumio volumio[814]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 15 Mar 28 19:03:10 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:10 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:10 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:10 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:10 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:10 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:10 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:10 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:10 volumio systemd[1]: Starting Music Player Daemon... Mar 28 19:03:10 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 28 19:03:10 volumio sudo[1059]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:10 volumio sudo[1060]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:10 volumio sudo[1055]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:10 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:10 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:10 volumio volumio[814]: info: FusionDsp - {"Reload":{"result":"Ok"}} Mar 28 19:03:10 volumio systemd[1]: Started Volumio Kiosk. Mar 28 19:03:10 volumio sudo[1093]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:10 volumio volumio[814]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Mar 28 19:03:10 volumio volumio[814]: info: touch_display: Volumio Kiosk started Mar 28 19:03:10 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Mar 28 19:03:10 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:10 volumio volumio[814]: info: Shairport-Sync Started Mar 28 19:03:10 volumio volumio[814]: Error adding Membership: Error: addMembership EINVAL Mar 28 19:03:10 volumio volumio[814]: info: Shairport-Sync Started Mar 28 19:03:10 volumio volumio[814]: info: Shairport-Sync Started Mar 28 19:03:10 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Mar 28 19:03:10 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:10 volumio volumio[814]: info: Starting Shairport Sync Mar 28 19:03:10 volumio go-librespot[1094]: time="2024-03-28T19:03:10Z" level=info msg="generated new device id: f8c69f513704b795f9ec6c2e165089573ff2976a" Mar 28 19:03:10 volumio go-librespot[1094]: time="2024-03-28T19:03:10Z" level=debug msg="stored credentials found for 11100610055" Mar 28 19:03:10 volumio sudo[1136]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 19:03:10 volumio sudo[1136]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:10 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 28 19:03:10 volumio startx[1111]: X.Org X Server 1.20.4 Mar 28 19:03:10 volumio startx[1111]: X Protocol Version 11, Revision 0 Mar 28 19:03:10 volumio startx[1111]: Build Operating System: Linux 5.4.0-109-generic armv8l Raspbian Mar 28 19:03:10 volumio startx[1111]: Current Operating System: Linux volumio 6.1.69-v7+ #1710 SMP Thu Dec 21 13:14:13 GMT 2023 armv7l Mar 28 19:03:10 volumio startx[1111]: Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_headphones=0 snd_bcm2835.enable_headphones=1 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=640 bcm2708_fb.fbheight=480 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 splash plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyS0,115200 console=tty1 imgpart=/dev/mmcblk0p2 imgfile=/volumio_current.sqsh rootwait bootdelay=5 elevator=noop logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd-bcm2835.enable_compat_alsa= snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 loglevel=0 Mar 28 19:03:10 volumio startx[1111]: Build Date: 04 August 2022 12:56:42PM Mar 28 19:03:10 volumio startx[1111]: xorg-server 2:1.20.4-1+rpt4+deb10u5 (https://www.debian.org/support) Mar 28 19:03:10 volumio startx[1111]: Current version of pixman: 0.36.0 Mar 28 19:03:10 volumio startx[1111]: Before reporting problems, check http://wiki.x.org Mar 28 19:03:10 volumio startx[1111]: to make sure that you have the latest version. Mar 28 19:03:10 volumio startx[1111]: Markers: (--) probed, (**) from config file, (==) default setting, Mar 28 19:03:10 volumio startx[1111]: (++) from command line, (!!) notice, (II) informational, Mar 28 19:03:10 volumio startx[1111]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Mar 28 19:03:10 volumio startx[1111]: (==) Log file: "/var/log/Xorg.0.log", Time: Thu Mar 28 19:03:10 2024 Mar 28 19:03:10 volumio systemd[1]: shairport-sync.service: Succeeded. Mar 28 19:03:10 volumio startx[1111]: (==) Using config directory: "/etc/X11/xorg.conf.d" Mar 28 19:03:10 volumio startx[1111]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Mar 28 19:03:10 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 28 19:03:11 volumio volumio[814]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Mar 28 19:03:11 volumio volumio[814]: info: Asound.conf file unchanged, so no further update is needed Mar 28 19:03:11 volumio volumio[814]: info: Output device has changed, restarting MPD Mar 28 19:03:11 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 28 19:03:11 volumio volumio[814]: info: Output device has changed, restarting Shairport Sync Mar 28 19:03:11 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:11 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:11 volumio sudo[1136]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:11 volumio sudo[1144]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 28 19:03:11 volumio sudo[1144]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:11 volumio sudo[1146]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 28 19:03:11 volumio sudo[1146]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:11 volumio sudo[1144]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:11 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Mar 28 19:03:11 volumio systemd[1]: mpd.service: Succeeded. Mar 28 19:03:11 volumio systemd[1]: Stopped Music Player Daemon. Mar 28 19:03:11 volumio volumio[814]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 19:03:11 volumio volumio[814]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Mar 28 19:03:11 volumio systemd[1]: Starting Music Player Daemon... Mar 28 19:03:11 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Mar 28 19:03:11 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:11 volumio volumio[814]: info: MPD Permissions set Mar 28 19:03:11 volumio volumio[814]: info: Shairport-Sync Started Mar 28 19:03:11 volumio volumio[814]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Mar 28 19:03:11 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:11 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:11 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:11 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:11 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:11 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:11 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:11 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:11 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:11 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:11 volumio volumio[814]: info: Starting Shairport Sync Mar 28 19:03:12 volumio volumio[814]: SPOTIFY: User informations: {"display_name":"DJK","external_urls":{"spotify":"https://open.spotify.com/user/11100610055"},"href":"https://api.spotify.com/v1/users/11100610055","id":"11100610055","images":[{"url":"https://i.scdn.co/image/ab67757000003b827f8f2aab6f5acab5367fcadd","height":64,"width":64},{"url":"https://i.scdn.co/image/ab6775700000ee857f8f2aab6f5acab5367fcadd","height":300,"width":300}],"type":"user","uri":"spotify:user:11100610055","followers":{"href":null,"total":350},"country":"AR","product":"premium","explicit_content":{"filter_enabled":false,"filter_locked":false},"email":"kolldamian@gmail.com"} Mar 28 19:03:12 volumio volumio[814]: info: Spotify Successfully logged in Mar 28 19:03:12 volumio volumio[814]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 19:03:12 volumio volumio[814]: info: [1711652592153] CoreMusicLibrary::Adding element Spotify Mar 28 19:03:12 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 19:03:12 volumio volumio[814]: Cannot find translation for source Bandcamp Discover Mar 28 19:03:12 volumio volumio[814]: Cannot find translation for source 80s80s Radio Mar 28 19:03:12 volumio volumio[814]: Cannot find translation for source Calm Radio Mar 28 19:03:12 volumio volumio[814]: Cannot find translation for source Mother Earth Radio Mar 28 19:03:12 volumio volumio[814]: Cannot find translation for source Podcast Mar 28 19:03:12 volumio volumio[814]: Cannot find translation for source Spotify Mar 28 19:03:12 volumio sudo[1166]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 19:03:12 volumio sudo[1166]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:12 volumio go-librespot[1094]: time="2024-03-28T19:03:12Z" level=debug msg="obtained new client token: AABuDRjbKbqgkj9bjq5BRSYmx9ze4puKZwY9xZFmsLnxDdBN5uBQcHvkDQNO5Arf+eALyAkr7cQwrjdmrwVwrKdPam2Gj7cQrquNDYa6D+ve6M8kRHr4hH4uXmRNfKp6jcwA2Sz9FvJVwMiGAMludxdBrb/41SOfF0VjDd3oYwQ6H9ohf1fUIjNAJzRD2/LO6iBnyKPP/6rcZGvm7YzflapBnsuS7Q9++3zY3ku12OZujehNOGIMuN4Osnr0IQ==" Mar 28 19:03:12 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 28 19:03:12 volumio systemd[1]: shairport-sync.service: Succeeded. Mar 28 19:03:12 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 28 19:03:12 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 28 19:03:12 volumio sudo[1166]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:12 volumio volumio[814]: info: Shairport-Sync Started Mar 28 19:03:12 volumio go-librespot[1094]: time="2024-03-28T19:03:12Z" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 28 19:03:13 volumio go-librespot[1094]: time="2024-03-28T19:03:13Z" level=debug msg="completed keyexchange" Mar 28 19:03:13 volumio volumio[814]: info: go-librespot daemon successfully initialized Mar 28 19:03:13 volumio go-librespot[1094]: time="2024-03-28T19:03:13Z" level=debug msg="completed challenge" Mar 28 19:03:13 volumio go-librespot[1094]: time="2024-03-28T19:03:13Z" level=debug msg="authenticated as 11100610055" Mar 28 19:03:14 volumio go-librespot[1094]: time="2024-03-28T19:03:14Z" level=debug msg="authenticated as 11100610055" Mar 28 19:03:14 volumio go-librespot[1094]: time="2024-03-28T19:03:14Z" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 28 19:03:14 volumio go-librespot[1094]: time="2024-03-28T19:03:14Z" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 28 19:03:14 volumio volumio[814]: info: touch_display: Setting screensaver timeout to 60 seconds. Mar 28 19:03:14 volumio mpd[1154]: Mar 28 19:03 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 28 19:03:14 volumio systemd[1]: Started Music Player Daemon. Mar 28 19:03:14 volumio sudo[989]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:14 volumio sudo[1013]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:14 volumio sudo[1146]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:14 volumio sudo[1067]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:14 volumio go-librespot[1094]: time="2024-03-28T19:03:14Z" level=debug msg="dealer connection opened" Mar 28 19:03:14 volumio go-librespot[1094]: time="2024-03-28T19:03:14Z" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Mar 28 19:03:14 volumio go-librespot[1094]: time="2024-03-28T19:03:14Z" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Mar 28 19:03:14 volumio volumio[814]: info: Completed starting Core Plugins Mar 28 19:03:14 volumio volumio[814]: info: ------------------------------------------- Mar 28 19:03:14 volumio volumio[814]: info: ----- MyVolumio plugins startup ---- Mar 28 19:03:14 volumio volumio[814]: info: ------------------------------------------- Mar 28 19:03:14 volumio go-librespot[1094]: time="2024-03-28T19:03:14Z" level=debug msg="received connection id: NTU2MDZiYjUtMzE0ZC00NjZiLTkxYzctODZjYjEzZTJiNTY0K2RlYWxlcit0Y3A6Ly9ndWMzLWRlYWxlci1hLXQ1ODMuZ3VjMy5zcG90aWZ5Lm5ldDo1NzAwKzc4QkM1NkYwREIyNzRCQkU3RjkzNkYwQTQxNTk2NzJERkJDMjM1MTk0QkMwQkIyMUNCRDY4N0QwQjY3RDc0Q0Y=" Mar 28 19:03:14 volumio go-librespot[1094]: time="2024-03-28T19:03:14Z" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Mar 28 19:03:14 volumio go-librespot[1094]: time="2024-03-28T19:03:14Z" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Mar 28 19:03:14 volumio go-librespot[1094]: time="2024-03-28T19:03:14Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513" Mar 28 19:03:14 volumio volumio[814]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 28 19:03:14 volumio volumio[814]: info: MPD running with PID1154 Mar 28 19:03:14 volumio volumio[814]: ,establishing connection Mar 28 19:03:15 volumio volumio[814]: error: MPD error: The expression evaluated to a falsy value: Mar 28 19:03:15 volumio volumio[814]: assert.ok(self.idling) Mar 28 19:03:15 volumio volumio[814]: error: The expression evaluated to a falsy value: Mar 28 19:03:15 volumio volumio[814]: assert.ok(self.idling) Mar 28 19:03:15 volumio volumio[814]: error: MPD error: The expression evaluated to a falsy value: Mar 28 19:03:15 volumio volumio[814]: assert.ok(self.idling) Mar 28 19:03:15 volumio volumio[814]: error: The expression evaluated to a falsy value: Mar 28 19:03:15 volumio volumio[814]: assert.ok(self.idling) Mar 28 19:03:15 volumio volumio[814]: error: MPD error: The expression evaluated to a falsy value: Mar 28 19:03:15 volumio volumio[814]: assert.ok(self.idling) Mar 28 19:03:15 volumio volumio[814]: error: The expression evaluated to a falsy value: Mar 28 19:03:15 volumio volumio[814]: assert.ok(self.idling) Mar 28 19:03:15 volumio volumio[814]: error: MPD error: The expression evaluated to a falsy value: Mar 28 19:03:15 volumio volumio[814]: assert.ok(self.idling) Mar 28 19:03:15 volumio volumio[814]: error: The expression evaluated to a falsy value: Mar 28 19:03:15 volumio volumio[814]: assert.ok(self.idling) Mar 28 19:03:15 volumio volumio[814]: error: updateQueue error: null Mar 28 19:03:15 volumio go-librespot[1094]: time="2024-03-28T19:03:15Z" level=debug msg="put connect state because NEW_DEVICE" Mar 28 19:03:16 volumio volumio[814]: info: Initializing connection to go-librespot Websocket Mar 28 19:03:16 volumio go-librespot[1094]: time="2024-03-28T19:03:16Z" level=debug msg="new websocket client" Mar 28 19:03:16 volumio volumio[814]: info: Connection to go-librespot Websocket established Mar 28 19:03:16 volumio volumio[949]: Generating RSA private key, 4096 bit long modulus (2 primes) Mar 28 19:03:19 volumio volumio[814]: info: Getting Spotify volume Mar 28 19:03:19 volumio volumio[814]: info: Spotify volume: 100 Mar 28 19:03:19 volumio volumio[814]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 16 Mar 28 19:03:19 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Mar 28 19:03:19 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:19 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 28 19:03:19 volumio volumio[814]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 28 19:03:23 volumio volumio[814]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 28 19:03:23 volumio volumio[814]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 28 19:03:23 volumio volumio[814]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 28 19:03:23 volumio volumio[814]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 28 19:03:23 volumio volumio[814]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 28 19:03:23 volumio volumio[814]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 28 19:03:23 volumio volumio[814]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 28 19:03:23 volumio volumio[814]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 28 19:03:23 volumio volumio[814]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 28 19:03:23 volumio volumio[814]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 28 19:03:23 volumio volumio[814]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 28 19:03:23 volumio volumio[814]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 28 19:03:23 volumio volumio[814]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 28 19:03:23 volumio volumio[814]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 28 19:03:23 volumio volumio[814]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 28 19:03:23 volumio volumio[814]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 28 19:03:23 volumio volumio[814]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 28 19:03:23 volumio volumio[814]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 28 19:03:23 volumio volumio[814]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 28 19:03:23 volumio volumio[814]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 28 19:03:23 volumio volumio[814]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 28 19:03:23 volumio volumio[814]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 28 19:03:23 volumio volumio[814]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 28 19:03:23 volumio volumio[814]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 28 19:03:23 volumio volumio[814]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 28 19:03:23 volumio volumio[814]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 28 19:03:23 volumio volumio[814]: info: Adding plugin bluetooth to MyMusic Plugins Mar 28 19:03:23 volumio volumio[814]: info: Adding plugin multiroom to MyMusic Plugins Mar 28 19:03:23 volumio volumio[814]: info: Adding plugin metavolumio to MyMusic Plugins Mar 28 19:03:23 volumio volumio[814]: info: Adding plugin cd_controller to MyMusic Plugins Mar 28 19:03:23 volumio volumio[814]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 28 19:03:23 volumio volumio[814]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 28 19:03:23 volumio volumio[814]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 28 19:03:27 volumio volumio[814]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 28 19:03:27 volumio volumio[814]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 28 19:03:27 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:27 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:27 volumio volumio[814]: info: Starting MyVolumio Remote Streaming Endpoints Mar 28 19:03:27 volumio volumio[814]: info: MyVolumio login type: Token Mar 28 19:03:27 volumio volumio[814]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 28 19:03:27 volumio volumio[814]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 28 19:03:31 volumio volumio[814]: info: Starting Streaming Service Transparent Proxy Mar 28 19:03:31 volumio volumio[814]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 28 19:03:31 volumio volumio[814]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 28 19:03:31 volumio volumio[814]: info: Streaming services startup Mar 28 19:03:31 volumio volumio[814]: info: Starting Streaming Daemon Mar 28 19:03:31 volumio volumio[814]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 28 19:03:31 volumio volumio[814]: info: AutoStart - Plugin is starting Mar 28 19:03:31 volumio volumio[814]: info: CoreCommandRouter::volumioGetQueue Mar 28 19:03:31 volumio volumio[814]: info: CoreStateMachine::getQueue Mar 28 19:03:31 volumio volumio[814]: info: CorePlayQueue::getQueue Mar 28 19:03:31 volumio volumio[814]: info: AutoStart - start playing Mar 28 19:03:31 volumio volumio[814]: info: AutoStart - start playing with no specific position Mar 28 19:03:31 volumio volumio[814]: info: CoreCommandRouter::volumioPlay Mar 28 19:03:31 volumio volumio[814]: info: CoreStateMachine::play index 0 Mar 28 19:03:31 volumio volumio[814]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 19:03:31 volumio volumio[814]: info: CoreStateMachine::stop Mar 28 19:03:31 volumio volumio[814]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 19:03:31 volumio volumio[814]: info: CoreStateMachine::play index undefined Mar 28 19:03:31 volumio volumio[814]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 19:03:31 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:31 volumio volumio[814]: info: CoreStateMachine::startPlaybackTimer Mar 28 19:03:31 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:31 volumio volumio[814]: info: [1711652611505] [80s80s] clearAddPlayTrack url: http://streams.80s80s.de/web/mp3-192/volumio Mar 28 19:03:31 volumio volumio[814]: info: [1711652611507] [80s80s] getContentOfUrl started with url http://iris-80s80s.loverad.io/flow.json?station=62&count=2 Mar 28 19:03:32 volumio volumio[814]: info: CoreCommandRouter::volumioPlay Mar 28 19:03:32 volumio volumio[814]: info: CoreStateMachine::play index undefined Mar 28 19:03:32 volumio volumio[814]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 19:03:32 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:32 volumio volumio[814]: info: CoreStateMachine::startPlaybackTimer Mar 28 19:03:32 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:32 volumio volumio[814]: info: [1711652612088] [80s80s] clearAddPlayTrack url: http://streams.80s80s.de/web/mp3-192/volumio Mar 28 19:03:32 volumio volumio[814]: info: [1711652612089] [80s80s] getContentOfUrl started with url http://iris-80s80s.loverad.io/flow.json?station=62&count=2 Mar 28 19:03:32 volumio sudo[1382]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 28 19:03:32 volumio sudo[1382]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:32 volumio sudo[1382]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:32 volumio volumio[814]: error: Cannot start Volumio Streaming Daemon Mar 28 19:03:32 volumio volumio[814]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 28 19:03:32 volumio volumio[814]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 28 19:03:32 volumio volumio[814]: info: [1711652612527] [80s80s] received new event containing 2 songs. Mar 28 19:03:32 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand stop Mar 28 19:03:32 volumio volumio[814]: info: sendMpdCommand stop took 90 milliseconds Mar 28 19:03:32 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand clear Mar 28 19:03:32 volumio volumio[814]: info: Mar 28 19:03:32 volumio volumio[814]: ---------------------------- MPD announces system playlist update Mar 28 19:03:32 volumio volumio[814]: info: Ignoring MPD Status Update Mar 28 19:03:32 volumio volumio[814]: info: sendMpdCommand clear took 9 milliseconds Mar 28 19:03:32 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand consume 1 Mar 28 19:03:32 volumio volumio[814]: info: Mar 28 19:03:32 volumio volumio[814]: ---------------------------- MPD announces system playlist update Mar 28 19:03:32 volumio volumio[814]: info: Ignoring MPD Status Update Mar 28 19:03:32 volumio volumio[814]: info: Mar 28 19:03:32 volumio volumio[814]: ---------------------------- MPD announces system playlist update Mar 28 19:03:32 volumio volumio[814]: info: Ignoring MPD Status Update Mar 28 19:03:32 volumio volumio[814]: info: Mar 28 19:03:32 volumio volumio[814]: ---------------------------- MPD announces system playlist update Mar 28 19:03:32 volumio volumio[814]: info: Ignoring MPD Status Update Mar 28 19:03:32 volumio volumio[814]: info: Mar 28 19:03:32 volumio volumio[814]: ---------------------------- MPD announces system playlist update Mar 28 19:03:32 volumio volumio[814]: info: Ignoring MPD Status Update Mar 28 19:03:32 volumio volumio[814]: error: updateQueue error: null Mar 28 19:03:32 volumio volumio[814]: info: Mar 28 19:03:32 volumio volumio[814]: ---------------------------- MPD announces state update: options Mar 28 19:03:32 volumio volumio[814]: error: updateQueue error: null Mar 28 19:03:32 volumio volumio[814]: error: updateQueue error: null Mar 28 19:03:32 volumio volumio[814]: error: updateQueue error: null Mar 28 19:03:32 volumio volumio[814]: error: updateQueue error: null Mar 28 19:03:32 volumio volumio[814]: info: ------------------------------ 60ms Mar 28 19:03:32 volumio volumio[814]: info: sendMpdCommand consume 1 took 55 milliseconds Mar 28 19:03:32 volumio volumio[814]: info: ControllerMpd::getState Mar 28 19:03:32 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:03:32 volumio volumio[814]: info: ------------------------------ 76ms Mar 28 19:03:32 volumio volumio[814]: info: ------------------------------ 73ms Mar 28 19:03:32 volumio volumio[814]: info: ------------------------------ 70ms Mar 28 19:03:32 volumio volumio[814]: info: ------------------------------ 57ms Mar 28 19:03:32 volumio volumio[814]: info: [1711652612721] [80s80s] adding url: http://streams.80s80s.de/web/mp3-192/volumio Mar 28 19:03:32 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand add "http://streams.80s80s.de/web/mp3-192/volumio" Mar 28 19:03:32 volumio volumio[814]: info: Mar 28 19:03:32 volumio volumio[814]: ---------------------------- MPD announces state update: options Mar 28 19:03:32 volumio volumio[814]: info: ControllerMpd::getState Mar 28 19:03:32 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:03:32 volumio volumio[814]: info: Mar 28 19:03:32 volumio volumio[814]: ---------------------------- MPD announces state update: options Mar 28 19:03:32 volumio volumio[814]: info: ControllerMpd::getState Mar 28 19:03:32 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:03:32 volumio volumio[814]: info: Mar 28 19:03:32 volumio volumio[814]: ---------------------------- MPD announces state update: options Mar 28 19:03:32 volumio volumio[814]: info: ControllerMpd::getState Mar 28 19:03:32 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:03:32 volumio volumio[814]: info: Mar 28 19:03:32 volumio volumio[814]: ---------------------------- MPD announces state update: options Mar 28 19:03:32 volumio volumio[814]: info: ControllerMpd::getState Mar 28 19:03:32 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:03:32 volumio volumio[814]: info: [1711652612795] [80s80s] received new event containing 2 songs. Mar 28 19:03:32 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand stop Mar 28 19:03:32 volumio volumio[814]: info: Mar 28 19:03:32 volumio volumio[814]: ---------------------------- MPD announces system playlist update Mar 28 19:03:32 volumio volumio[814]: info: Ignoring MPD Status Update Mar 28 19:03:32 volumio volumio[814]: info: sendMpdCommand status took 91 milliseconds Mar 28 19:03:32 volumio volumio[814]: info: sendMpdCommand add "http://streams.80s80s.de/web/mp3-192/volumio" took 75 milliseconds Mar 28 19:03:32 volumio volumio[814]: info: sendMpdCommand status took 57 milliseconds Mar 28 19:03:32 volumio volumio[814]: info: sendMpdCommand status took 54 milliseconds Mar 28 19:03:32 volumio volumio[814]: info: sendMpdCommand status took 41 milliseconds Mar 28 19:03:32 volumio volumio[814]: info: sendMpdCommand status took 37 milliseconds Mar 28 19:03:32 volumio volumio[814]: info: sendMpdCommand stop took 20 milliseconds Mar 28 19:03:32 volumio volumio[814]: verbose: ControllerMpd::parseState Mar 28 19:03:32 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand play Mar 28 19:03:32 volumio volumio[814]: verbose: ControllerMpd::parseState Mar 28 19:03:32 volumio volumio[814]: verbose: ControllerMpd::parseState Mar 28 19:03:32 volumio volumio[814]: verbose: ControllerMpd::parseState Mar 28 19:03:32 volumio volumio[814]: verbose: ControllerMpd::parseState Mar 28 19:03:32 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand clear Mar 28 19:03:32 volumio volumio[814]: info: ControllerMpd::pushState Mar 28 19:03:32 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:03:32 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:03:32 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:32 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:03:32 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:03:32 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:32 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 28 19:03:32 volumio volumio[814]: info: ControllerMpd::pushState Mar 28 19:03:32 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:03:32 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:03:32 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:32 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:03:32 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:32 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 28 19:03:32 volumio volumio[814]: info: ControllerMpd::pushState Mar 28 19:03:32 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:03:32 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:03:32 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:32 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:03:32 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:32 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 28 19:03:32 volumio volumio[814]: info: ControllerMpd::pushState Mar 28 19:03:32 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:03:32 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:03:32 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:32 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:03:32 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:32 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 28 19:03:32 volumio volumio[814]: info: ControllerMpd::pushState Mar 28 19:03:32 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:03:32 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:03:32 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:32 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:03:32 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:32 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 28 19:03:32 volumio volumio[814]: info: ------------------------------ 308ms Mar 28 19:03:33 volumio volumio[814]: info: ------------------------------ 465ms Mar 28 19:03:33 volumio volumio[814]: info: ------------------------------ 452ms Mar 28 19:03:33 volumio volumio[814]: info: ------------------------------ 450ms Mar 28 19:03:33 volumio volumio[814]: info: ------------------------------ 437ms Mar 28 19:03:33 volumio volumio[814]: info: Mar 28 19:03:33 volumio volumio[814]: ---------------------------- MPD announces system playlist update Mar 28 19:03:33 volumio volumio[814]: info: Ignoring MPD Status Update Mar 28 19:03:33 volumio volumio[814]: info: Mar 28 19:03:33 volumio volumio[814]: ---------------------------- MPD announces system playlist update Mar 28 19:03:33 volumio volumio[814]: info: Ignoring MPD Status Update Mar 28 19:03:33 volumio volumio[814]: info: Mar 28 19:03:33 volumio volumio[814]: ---------------------------- MPD announces system playlist update Mar 28 19:03:33 volumio volumio[814]: info: Ignoring MPD Status Update Mar 28 19:03:33 volumio volumio[814]: info: Mar 28 19:03:33 volumio volumio[814]: ---------------------------- MPD announces system playlist update Mar 28 19:03:33 volumio volumio[814]: info: Ignoring MPD Status Update Mar 28 19:03:33 volumio volumio[814]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 28 19:03:33 volumio volumio[814]: info: Mar 28 19:03:33 volumio volumio[814]: ---------------------------- MPD announces system playlist update Mar 28 19:03:33 volumio volumio[814]: info: Ignoring MPD Status Update Mar 28 19:03:33 volumio volumio[814]: info: Mar 28 19:03:33 volumio volumio[814]: ---------------------------- MPD announces state update: player Mar 28 19:03:33 volumio volumio[814]: error: updateQueue error: null Mar 28 19:03:33 volumio volumio[814]: error: updateQueue error: null Mar 28 19:03:33 volumio volumio[814]: error: updateQueue error: null Mar 28 19:03:33 volumio volumio[814]: error: updateQueue error: null Mar 28 19:03:33 volumio volumio[814]: info: ------------------------------ 696ms Mar 28 19:03:33 volumio volumio[814]: info: sendMpdCommand play took 637 milliseconds Mar 28 19:03:33 volumio volumio[814]: info: sendMpdCommand clear took 623 milliseconds Mar 28 19:03:33 volumio volumio[814]: info: ControllerMpd::getState Mar 28 19:03:33 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:03:33 volumio volumio[814]: info: ------------------------------ 285ms Mar 28 19:03:33 volumio volumio[814]: info: ------------------------------ 283ms Mar 28 19:03:33 volumio volumio[814]: info: ------------------------------ 267ms Mar 28 19:03:33 volumio volumio[814]: info: ------------------------------ 265ms Mar 28 19:03:33 volumio volumio[814]: info: [1711652613505] [80s80s] Pushing the next song state: Bananarama - I Heard a Rumour Mar 28 19:03:33 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:33 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:03:33 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:33 volumio volumio[814]: verbose: STATE SERVICE {"status":"play","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is1-ssl.mzstatic.com/image/thumb/Music/v4/9c/07/ec/9c07ec9a-954f-4e3a-45eb-363df21027ae/source/600x600bb.jpg","name":"Bananarama - I Heard a Rumour","title":"I Heard a Rumour","artist":"80s80s Real 80s Radio","album":"","streaming":true,"disableUiControls":true,"duration":"195","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Mar 28 19:03:33 volumio volumio[814]: verbose: CURRENT POSITION 0 Mar 28 19:03:33 volumio volumio[814]: info: CoreStateMachine::syncState stateService play Mar 28 19:03:33 volumio volumio[814]: info: CoreStateMachine::syncState currentStatus stop Mar 28 19:03:33 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand consume 1 Mar 28 19:03:33 volumio volumio[814]: info: [1711652613518] [80s80s] PlayNextTrack API delay: 30 Mar 28 19:03:33 volumio volumio[814]: info: [1711652613578] [80s80s] Setting timer to: 195000 milliseconds. Mar 28 19:03:33 volumio volumio[814]: info: Mar 28 19:03:33 volumio volumio[814]: ---------------------------- MPD announces system playlist update Mar 28 19:03:33 volumio volumio[814]: info: Ignoring MPD Status Update Mar 28 19:03:33 volumio volumio[814]: info: Mar 28 19:03:33 volumio volumio[814]: ---------------------------- MPD announces state update: player Mar 28 19:03:33 volumio volumio[814]: info: ControllerMpd::getState Mar 28 19:03:33 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:03:33 volumio volumio[814]: info: Mar 28 19:03:33 volumio volumio[814]: ---------------------------- MPD announces system playlist update Mar 28 19:03:33 volumio volumio[814]: info: Ignoring MPD Status Update Mar 28 19:03:33 volumio volumio[814]: info: Mar 28 19:03:33 volumio volumio[814]: ---------------------------- MPD announces state update: player Mar 28 19:03:33 volumio volumio[814]: info: ControllerMpd::getState Mar 28 19:03:33 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:03:33 volumio volumio[814]: info: Mar 28 19:03:33 volumio volumio[814]: ---------------------------- MPD announces system playlist update Mar 28 19:03:33 volumio volumio[814]: info: Ignoring MPD Status Update Mar 28 19:03:33 volumio volumio[814]: info: Mar 28 19:03:33 volumio volumio[814]: ---------------------------- MPD announces state update: player Mar 28 19:03:33 volumio volumio[814]: info: ControllerMpd::getState Mar 28 19:03:33 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:03:33 volumio volumio[814]: info: Mar 28 19:03:33 volumio volumio[814]: ---------------------------- MPD announces system playlist update Mar 28 19:03:33 volumio volumio[814]: info: Ignoring MPD Status Update Mar 28 19:03:33 volumio volumio[814]: info: Mar 28 19:03:33 volumio volumio[814]: ---------------------------- MPD announces state update: player Mar 28 19:03:33 volumio volumio[814]: info: ControllerMpd::getState Mar 28 19:03:33 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:03:33 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 28 19:03:33 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 28 19:03:33 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 28 19:03:33 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 28 19:03:33 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 28 19:03:33 volumio volumio[814]: error: updateQueue error: null Mar 28 19:03:33 volumio volumio[814]: error: updateQueue error: null Mar 28 19:03:33 volumio volumio[814]: error: updateQueue error: null Mar 28 19:03:33 volumio volumio[814]: error: updateQueue error: null Mar 28 19:03:33 volumio volumio[814]: error: updateQueue error: null Mar 28 19:03:33 volumio volumio[814]: info: ------------------------------ 234ms Mar 28 19:03:33 volumio volumio[814]: info: sendMpdCommand status took 224 milliseconds Mar 28 19:03:33 volumio volumio[814]: info: sendMpdCommand consume 1 took 211 milliseconds Mar 28 19:03:33 volumio volumio[814]: info: ------------------------------ 142ms Mar 28 19:03:33 volumio volumio[814]: info: sendMpdCommand status took 139 milliseconds Mar 28 19:03:33 volumio volumio[814]: info: ------------------------------ 138ms Mar 28 19:03:33 volumio volumio[814]: info: sendMpdCommand status took 135 milliseconds Mar 28 19:03:33 volumio volumio[814]: info: ------------------------------ 134ms Mar 28 19:03:33 volumio volumio[814]: info: sendMpdCommand status took 129 milliseconds Mar 28 19:03:33 volumio volumio[814]: info: ------------------------------ 128ms Mar 28 19:03:33 volumio volumio[814]: info: sendMpdCommand status took 121 milliseconds Mar 28 19:03:33 volumio volumio[814]: verbose: ControllerMpd::parseState Mar 28 19:03:33 volumio volumio[814]: info: [1711652613741] [80s80s] adding url: http://streams.80s80s.de/web/mp3-192/volumio Mar 28 19:03:33 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand add "http://streams.80s80s.de/web/mp3-192/volumio" Mar 28 19:03:33 volumio volumio[814]: verbose: ControllerMpd::parseState Mar 28 19:03:33 volumio volumio[814]: verbose: ControllerMpd::parseState Mar 28 19:03:33 volumio volumio[814]: verbose: ControllerMpd::parseState Mar 28 19:03:33 volumio volumio[814]: verbose: ControllerMpd::parseState Mar 28 19:03:33 volumio volumio[814]: info: ControllerMpd::pushState Mar 28 19:03:33 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:03:33 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:03:33 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:33 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:03:33 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:03:33 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:33 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 28 19:03:33 volumio volumio[814]: info: ControllerMpd::pushState Mar 28 19:03:33 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:03:33 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:03:33 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:33 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:03:33 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:33 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 28 19:03:33 volumio volumio[814]: info: ControllerMpd::pushState Mar 28 19:03:33 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:03:33 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:03:33 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:33 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:03:33 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:33 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 28 19:03:33 volumio volumio[814]: info: ControllerMpd::pushState Mar 28 19:03:33 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:03:33 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:03:33 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:33 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:03:33 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:33 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 28 19:03:33 volumio volumio[814]: info: ControllerMpd::pushState Mar 28 19:03:33 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:03:33 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:03:33 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:33 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:03:33 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:33 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 28 19:03:33 volumio volumio[814]: info: ------------------------------ 480ms Mar 28 19:03:33 volumio volumio[814]: info: ------------------------------ 385ms Mar 28 19:03:33 volumio volumio[814]: info: ------------------------------ 381ms Mar 28 19:03:33 volumio volumio[814]: info: ------------------------------ 377ms Mar 28 19:03:33 volumio volumio[814]: info: ------------------------------ 368ms Mar 28 19:03:34 volumio volumio[814]: info: Mar 28 19:03:34 volumio volumio[814]: ---------------------------- MPD announces system playlist update Mar 28 19:03:34 volumio volumio[814]: info: Ignoring MPD Status Update Mar 28 19:03:34 volumio volumio[814]: info: sendMpdCommand add "http://streams.80s80s.de/web/mp3-192/volumio" took 310 milliseconds Mar 28 19:03:34 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand play Mar 28 19:03:34 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 28 19:03:34 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 28 19:03:34 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 28 19:03:34 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 28 19:03:34 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 28 19:03:34 volumio volumio[814]: info: Mar 28 19:03:34 volumio volumio[814]: ---------------------------- MPD announces system playlist update Mar 28 19:03:34 volumio volumio[814]: info: Ignoring MPD Status Update Mar 28 19:03:34 volumio volumio[814]: info: Mar 28 19:03:34 volumio volumio[814]: ---------------------------- MPD announces system playlist update Mar 28 19:03:34 volumio volumio[814]: info: Ignoring MPD Status Update Mar 28 19:03:34 volumio volumio[814]: info: Mar 28 19:03:34 volumio volumio[814]: ---------------------------- MPD announces system playlist update Mar 28 19:03:34 volumio volumio[814]: info: Ignoring MPD Status Update Mar 28 19:03:34 volumio volumio[814]: info: Mar 28 19:03:34 volumio volumio[814]: ---------------------------- MPD announces system playlist update Mar 28 19:03:34 volumio volumio[814]: info: Ignoring MPD Status Update Mar 28 19:03:34 volumio volumio[814]: info: ------------------------------ 237ms Mar 28 19:03:34 volumio volumio[814]: info: sendMpdCommand play took 216 milliseconds Mar 28 19:03:34 volumio volumio[814]: info: ------------------------------ 85ms Mar 28 19:03:34 volumio volumio[814]: info: ------------------------------ 77ms Mar 28 19:03:34 volumio volumio[814]: info: ------------------------------ 73ms Mar 28 19:03:34 volumio volumio[814]: info: ------------------------------ 69ms Mar 28 19:03:34 volumio volumio[814]: info: [1711652614303] [80s80s] Pushing the next song state: Bananarama - I Heard a Rumour Mar 28 19:03:34 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:34 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:03:34 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:34 volumio volumio[814]: verbose: STATE SERVICE {"status":"play","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is1-ssl.mzstatic.com/image/thumb/Music/v4/9c/07/ec/9c07ec9a-954f-4e3a-45eb-363df21027ae/source/600x600bb.jpg","name":"Bananarama - I Heard a Rumour","title":"I Heard a Rumour","artist":"80s80s Real 80s Radio","album":"","streaming":true,"disableUiControls":true,"duration":"195","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Mar 28 19:03:34 volumio volumio[814]: verbose: CURRENT POSITION 0 Mar 28 19:03:34 volumio volumio[814]: info: CoreStateMachine::syncState stateService play Mar 28 19:03:34 volumio volumio[814]: info: CoreStateMachine::syncState currentStatus play Mar 28 19:03:34 volumio volumio[814]: info: Received an update from plugin. extracting info from payload Mar 28 19:03:34 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:03:34 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:34 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:03:34 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:03:34 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:34 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:03:34 volumio volumio[814]: info: [1711652614415] [80s80s] PlayNextTrack API delay: 30 Mar 28 19:03:34 volumio volumio[814]: info: [1711652614426] [80s80s] Setting timer to: 195000 milliseconds. Mar 28 19:03:34 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:34 volumio volumio[814]: info: CorePlayQueue::getTrack 1 Mar 28 19:03:34 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 28 19:03:34 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 28 19:03:34 volumio volumio[814]: info: touch_display: Setting screensaver timeout to 0 seconds. Mar 28 19:03:34 volumio volumio[814]: STREAMING PROXY: Starting server on port 3245 Mar 28 19:03:34 volumio volumio[814]: Node JS runtime: 14 Mar 28 19:03:35 volumio volumio[814]: info: MyVolumio token set successfully Mar 28 19:03:35 volumio volumio[814]: info: MYVOLUMIO: Adding device Mar 28 19:03:35 volumio volumio[814]: info: MYVOLUMIO: Evaluating Server Mar 28 19:03:36 volumio volumio[814]: info: MyVolumio Plan changed: premium Mar 28 19:03:36 volumio volumio[814]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Mar 28 19:03:36 volumio volumio[814]: info: Removing browser output: myVolumio user plan is not superstar Mar 28 19:03:36 volumio volumio[814]: info: Removing audio output: Mar 28 19:03:36 volumio volumio[814]: info: MYVOLUMIO: Adding device Mar 28 19:03:36 volumio volumio[814]: info: MYVOLUMIO: Evaluating Server Mar 28 19:03:36 volumio volumio[814]: info: Remote config written successfully Mar 28 19:03:36 volumio volumio[814]: info: Starting Tunnel 1 Mar 28 19:03:36 volumio volumio[814]: info: Starting Tunnel Connection Checker Mar 28 19:03:36 volumio volumio[814]: info: Completed starting MyVolumio Plugin Mar 28 19:03:37 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 28 19:03:37 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:37 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 28 19:03:37 volumio volumio[814]: info: MYVolumio Device enabled Mar 28 19:03:37 volumio volumio[814]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Mar 28 19:03:37 volumio volumio[814]: info: MyVolumio status changed Mar 28 19:03:37 volumio volumio[814]: info: Streaming services startup Mar 28 19:03:37 volumio volumio[814]: info: Starting Streaming Daemon Mar 28 19:03:37 volumio sudo[1443]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 28 19:03:37 volumio volumio[814]: info: Setting Geolocation for MyVolumio to us1 Mar 28 19:03:37 volumio sudo[1443]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:37 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:37 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:37 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:37 volumio sudo[1443]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:37 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Mar 28 19:03:37 volumio volumio-remote-updater[500]: No test mode Mar 28 19:03:37 volumio volumio-remote-updater[500]: No alpha test mode Mar 28 19:03:37 volumio volumio[814]: error: Cannot start Volumio Streaming Daemon Mar 28 19:03:37 volumio volumio[814]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 28 19:03:37 volumio volumio[814]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 28 19:03:37 volumio volumio[814]: info: Setting Geolocation for MyVolumio to us1 Mar 28 19:03:37 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:37 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:37 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:37 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Mar 28 19:03:37 volumio volumio[814]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Mar 28 19:03:37 volumio volumio[814]: info: [1711652617960] Starting BluetoothController Mar 28 19:03:38 volumio volumio[814]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Mar 28 19:03:41 volumio volumio[814]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Mar 28 19:03:41 volumio sudo[1451]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Mar 28 19:03:41 volumio sudo[1451]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:41 volumio sudo[1451]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:42 volumio volumio[814]: info: MRS: MultiRoom plugin initialized Mar 28 19:03:42 volumio volumio[814]: info: MRS: STOPPING SNAPCLIENT Mar 28 19:03:42 volumio volumio[814]: info: MRS: Snap server stop Mar 28 19:03:42 volumio sudo[1467]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Mar 28 19:03:42 volumio sudo[1467]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:42 volumio volumio[814]: info: MRS: STOPPING volumioStreaming Mar 28 19:03:42 volumio sudo[1467]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:42 volumio volumio[814]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Mar 28 19:03:42 volumio sudo[1472]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Mar 28 19:03:42 volumio sudo[1470]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Mar 28 19:03:42 volumio sudo[1470]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:42 volumio sudo[1472]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:42 volumio sudo[1474]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Mar 28 19:03:42 volumio sudo[1474]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:42 volumio sudo[1474]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:42 volumio sudo[1470]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:42 volumio sudo[1472]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:42 volumio volumio[814]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Mar 28 19:03:42 volumio volumio[814]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Mar 28 19:03:42 volumio volumio[814]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Mar 28 19:03:42 volumio volumio[814]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Mar 28 19:03:42 volumio volumio[814]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Mar 28 19:03:42 volumio volumio[814]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Mar 28 19:03:43 volumio volumio[814]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Mar 28 19:03:43 volumio volumio[814]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Mar 28 19:03:43 volumio volumio[814]: info: Preparing to generate the ALSA configuration file Mar 28 19:03:43 volumio volumio[814]: info: Updating MyVolumio device info Mar 28 19:03:43 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:43 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:43 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:43 volumio volumio[814]: info: Updating MyVolumio device info Mar 28 19:03:43 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:43 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:43 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:43 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 28 19:03:43 volumio volumio[814]: info: The plugin peppy_screensaver has an ALSA contribution file Peppyalsa.postPeppyalsa.5.conf Mar 28 19:03:43 volumio volumio[814]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Mar 28 19:03:43 volumio volumio[814]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Mar 28 19:03:43 volumio volumio[814]: info: Reading ALSA contributions from plugins. Mar 28 19:03:43 volumio volumio[814]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 28 19:03:43 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 28 19:03:43 volumio volumio[814]: info: Mar 28 19:03:43 volumio volumio[814]: ---------------------------- MPD announces state update: player Mar 28 19:03:43 volumio volumio[814]: info: ControllerMpd::getState Mar 28 19:03:43 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:03:43 volumio volumio[814]: info: Mar 28 19:03:43 volumio volumio[814]: ---------------------------- MPD announces state update: player Mar 28 19:03:43 volumio volumio[814]: info: ControllerMpd::getState Mar 28 19:03:43 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:03:43 volumio volumio[814]: info: Mar 28 19:03:43 volumio volumio[814]: ---------------------------- MPD announces state update: player Mar 28 19:03:43 volumio volumio[814]: info: ControllerMpd::getState Mar 28 19:03:43 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:03:43 volumio volumio[814]: info: Mar 28 19:03:43 volumio volumio[814]: ---------------------------- MPD announces state update: player Mar 28 19:03:43 volumio volumio[814]: info: ControllerMpd::getState Mar 28 19:03:43 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:03:43 volumio volumio[814]: info: Mar 28 19:03:43 volumio volumio[814]: ---------------------------- MPD announces state update: player Mar 28 19:03:43 volumio volumio[814]: info: ControllerMpd::getState Mar 28 19:03:43 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:03:43 volumio volumio[814]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Mar 28 19:03:43 volumio volumio[814]: info: FusionDsp - ---- read samplerate from file: 44100 Mar 28 19:03:43 volumio volumio[814]: info: camilladsp stopping service pid 1078... Mar 28 19:03:43 volumio volumio[814]: info: camilladsp service terminated, instance 1 Mar 28 19:03:43 volumio volumio[814]: info: FusionDsp - If filter freq >samplerate/2 then disable it Mar 28 19:03:43 volumio volumio[814]: info: camilladsp service started and running in background, instance 1 Mar 28 19:03:44 volumio volumio[814]: info: MRS: Removed streaming files Mar 28 19:03:44 volumio volumio[814]: info: MRS: volumioStreaming STOPPED Mar 28 19:03:44 volumio volumio[814]: info: MRS: SNAPSERVER STOPPED Mar 28 19:03:44 volumio volumio[814]: info: MRS: SNAPCLIENT STOPPED Mar 28 19:03:44 volumio volumio[814]: info: Mar 28 19:03:44 volumio volumio[814]: ---------------------------- MPD announces system playlist update Mar 28 19:03:44 volumio volumio[814]: info: Ignoring MPD Status Update Mar 28 19:03:44 volumio volumio[814]: info: Mar 28 19:03:44 volumio volumio[814]: ---------------------------- MPD announces state update: player Mar 28 19:03:44 volumio volumio[814]: info: ControllerMpd::getState Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:03:44 volumio volumio[814]: info: sendMpdCommand status took 330 milliseconds Mar 28 19:03:44 volumio volumio[814]: info: sendMpdCommand status took 317 milliseconds Mar 28 19:03:44 volumio volumio[814]: info: sendMpdCommand status took 316 milliseconds Mar 28 19:03:44 volumio volumio[814]: info: sendMpdCommand status took 287 milliseconds Mar 28 19:03:44 volumio volumio[814]: info: sendMpdCommand status took 283 milliseconds Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::parseState Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::parseState Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::parseState Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::parseState Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::parseState Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 19:03:44 volumio volumio[814]: info: Mar 28 19:03:44 volumio volumio[814]: ---------------------------- MPD announces system playlist update Mar 28 19:03:44 volumio volumio[814]: info: Ignoring MPD Status Update Mar 28 19:03:44 volumio volumio[814]: info: Mar 28 19:03:44 volumio volumio[814]: ---------------------------- MPD announces state update: player Mar 28 19:03:44 volumio volumio[814]: info: ControllerMpd::getState Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:03:44 volumio volumio[814]: info: Mar 28 19:03:44 volumio volumio[814]: ---------------------------- MPD announces system playlist update Mar 28 19:03:44 volumio volumio[814]: info: Ignoring MPD Status Update Mar 28 19:03:44 volumio volumio[814]: info: Mar 28 19:03:44 volumio volumio[814]: ---------------------------- MPD announces state update: player Mar 28 19:03:44 volumio volumio[814]: info: ControllerMpd::getState Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:03:44 volumio volumio[814]: info: Mar 28 19:03:44 volumio volumio[814]: ---------------------------- MPD announces system playlist update Mar 28 19:03:44 volumio volumio[814]: info: Ignoring MPD Status Update Mar 28 19:03:44 volumio volumio[814]: info: Mar 28 19:03:44 volumio volumio[814]: ---------------------------- MPD announces state update: player Mar 28 19:03:44 volumio volumio[814]: info: ControllerMpd::getState Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:03:44 volumio volumio[814]: info: Mar 28 19:03:44 volumio volumio[814]: ---------------------------- MPD announces system playlist update Mar 28 19:03:44 volumio volumio[814]: info: Ignoring MPD Status Update Mar 28 19:03:44 volumio volumio[814]: info: Mar 28 19:03:44 volumio volumio[814]: ---------------------------- MPD announces state update: player Mar 28 19:03:44 volumio volumio[814]: info: ControllerMpd::getState Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:03:44 volumio volumio[814]: Upnp client error: Error: This socket has been ended by the other party Mar 28 19:03:44 volumio volumio[814]: info: ------------------------------ 162ms Mar 28 19:03:44 volumio volumio[814]: info: sendMpdCommand status took 154 milliseconds Mar 28 19:03:44 volumio volumio[814]: info: sendMpdCommand playlistinfo took 140 milliseconds Mar 28 19:03:44 volumio volumio[814]: info: sendMpdCommand playlistinfo took 141 milliseconds Mar 28 19:03:44 volumio volumio[814]: info: sendMpdCommand playlistinfo took 140 milliseconds Mar 28 19:03:44 volumio volumio[814]: info: sendMpdCommand playlistinfo took 141 milliseconds Mar 28 19:03:44 volumio volumio[814]: info: sendMpdCommand playlistinfo took 141 milliseconds Mar 28 19:03:44 volumio volumio[814]: info: ------------------------------ 140ms Mar 28 19:03:44 volumio volumio[814]: info: sendMpdCommand status took 134 milliseconds Mar 28 19:03:44 volumio volumio[814]: info: ------------------------------ 133ms Mar 28 19:03:44 volumio volumio[814]: info: sendMpdCommand status took 126 milliseconds Mar 28 19:03:44 volumio volumio[814]: info: ------------------------------ 125ms Mar 28 19:03:44 volumio volumio[814]: info: sendMpdCommand status took 118 milliseconds Mar 28 19:03:44 volumio volumio[814]: info: ------------------------------ 116ms Mar 28 19:03:44 volumio volumio[814]: info: sendMpdCommand status took 109 milliseconds Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::parseState Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::parseTrackInfo Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::parseTrackInfo Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::parseTrackInfo Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::parseTrackInfo Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::parseTrackInfo Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::parseState Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::parseState Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::parseState Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::parseState Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 19:03:44 volumio volumio[814]: info: ControllerMpd::pushState Mar 28 19:03:44 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:03:44 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:44 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 28 19:03:44 volumio volumio[814]: info: ControllerMpd::pushState Mar 28 19:03:44 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:03:44 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:44 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 28 19:03:44 volumio volumio[814]: info: ControllerMpd::pushState Mar 28 19:03:44 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:03:44 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:44 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 28 19:03:44 volumio volumio[814]: info: ControllerMpd::pushState Mar 28 19:03:44 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:03:44 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:44 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 28 19:03:44 volumio volumio[814]: info: ControllerMpd::pushState Mar 28 19:03:44 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:03:44 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:44 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 28 19:03:44 volumio volumio[814]: info: ------------------------------ 540ms Mar 28 19:03:44 volumio volumio[814]: info: ------------------------------ 525ms Mar 28 19:03:44 volumio volumio[814]: info: ------------------------------ 521ms Mar 28 19:03:44 volumio volumio[814]: info: ------------------------------ 507ms Mar 28 19:03:44 volumio volumio[814]: info: ------------------------------ 485ms Mar 28 19:03:44 volumio volumio[814]: Upnp client error: Error: This socket has been ended by the other party Mar 28 19:03:44 volumio volumio[814]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 17 Mar 28 19:03:44 volumio volumio[814]: info: camilladsp spawned new process with pid 1521, instance 1, run: true Mar 28 19:03:44 volumio volumio[814]: info: sendMpdCommand playlistinfo took 363 milliseconds Mar 28 19:03:44 volumio volumio[814]: info: sendMpdCommand playlistinfo took 355 milliseconds Mar 28 19:03:44 volumio volumio[814]: info: sendMpdCommand playlistinfo took 355 milliseconds Mar 28 19:03:44 volumio volumio[814]: info: sendMpdCommand playlistinfo took 355 milliseconds Mar 28 19:03:44 volumio volumio[814]: info: sendMpdCommand playlistinfo took 354 milliseconds Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::parseTrackInfo Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::parseTrackInfo Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::parseTrackInfo Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::parseTrackInfo Mar 28 19:03:44 volumio volumio[814]: verbose: ControllerMpd::parseTrackInfo Mar 28 19:03:44 volumio volumio[814]: info: ControllerMpd::pushState Mar 28 19:03:44 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:03:44 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:44 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 28 19:03:44 volumio volumio[814]: info: ControllerMpd::pushState Mar 28 19:03:44 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:03:44 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:44 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 28 19:03:44 volumio volumio[814]: info: ControllerMpd::pushState Mar 28 19:03:44 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:03:44 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:44 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 28 19:03:44 volumio volumio[814]: info: ControllerMpd::pushState Mar 28 19:03:44 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:03:44 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:44 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 28 19:03:44 volumio volumio[814]: info: ControllerMpd::pushState Mar 28 19:03:44 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:03:44 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:44 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Mar 28 19:03:44 volumio volumio[814]: info: ------------------------------ 571ms Mar 28 19:03:44 volumio volumio[814]: info: ------------------------------ 531ms Mar 28 19:03:44 volumio volumio[814]: info: ------------------------------ 522ms Mar 28 19:03:44 volumio volumio[814]: info: ------------------------------ 514ms Mar 28 19:03:44 volumio volumio[814]: info: ------------------------------ 503ms Mar 28 19:03:44 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Mar 28 19:03:44 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:44 volumio volumio[814]: info: Asound.conf file written Mar 28 19:03:44 volumio sudo[1535]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Mar 28 19:03:44 volumio sudo[1535]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:45 volumio sudo[1535]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:45 volumio volumio[814]: info: Output device has changed, restarting MPD Mar 28 19:03:45 volumio sudo[1541]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 28 19:03:45 volumio sudo[1541]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:45 volumio volumio[814]: info: Output device has changed, restarting Shairport Sync Mar 28 19:03:45 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:45 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:45 volumio sudo[1541]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:45 volumio sudo[1544]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 28 19:03:45 volumio sudo[1544]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:45 volumio systemd[1]: Stopping Music Player Daemon... Mar 28 19:03:45 volumio volumio[814]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 28 19:03:45 volumio volumio[814]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 28 19:03:45 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:45 volumio volumio[814]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Mar 28 19:03:45 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 28 19:03:46 volumio volumio[814]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Mar 28 19:03:46 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Mar 28 19:03:46 volumio volumio[814]: info: MRS: Pushing multiroomSync output for this device Mar 28 19:03:46 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:03:46 volumio sudo[1552]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name Volumio Mar 28 19:03:46 volumio sudo[1552]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:46 volumio systemd[1]: mpd.service: Succeeded. Mar 28 19:03:46 volumio systemd[1]: Stopped Music Player Daemon. Mar 28 19:03:46 volumio sudo[1552]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:46 volumio volumio[814]: info: Adding audio output: Mar 28 19:03:46 volumio volumio[814]: info: Adding audio output: Mar 28 19:03:46 volumio systemd[1]: Starting Music Player Daemon... Mar 28 19:03:46 volumio volumio[814]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 28 19:03:46 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:46 volumio volumio[814]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Mar 28 19:03:46 volumio volumio[814]: info: Adding METAVOLUMIO REST API Endpoints Mar 28 19:03:46 volumio volumio[814]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Mar 28 19:03:46 volumio volumio[814]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Mar 28 19:03:46 volumio volumio[814]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Mar 28 19:03:46 volumio volumio[814]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Mar 28 19:03:46 volumio volumio[814]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Mar 28 19:03:46 volumio volumio[814]: info: Adding Manifest REST API Endpoints Mar 28 19:03:46 volumio volumio[814]: info: Adding manifestui REST Endpoint for plugin: miscellanea/manifestui Mar 28 19:03:46 volumio volumio[814]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Mar 28 19:03:46 volumio volumio[814]: info: Preparing CD Folders Mar 28 19:03:46 volumio volumio[814]: info: Adding CD REST API Endpoints Mar 28 19:03:46 volumio volumio[814]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Mar 28 19:03:46 volumio volumio[814]: info: Starting UDEV Watcher for CD Mar 28 19:03:46 volumio volumio[814]: info: Detecting CD presence with UDEV Mar 28 19:03:46 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Mar 28 19:03:46 volumio volumio[814]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Mar 28 19:03:46 volumio volumio[814]: info: Adding inputs REST Endpoints Mar 28 19:03:46 volumio volumio[814]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Mar 28 19:03:46 volumio volumio[814]: info: Scanning Audio Inputs Mar 28 19:03:46 volumio volumio[814]: info: Checking against Known Cards name Mar 28 19:03:46 volumio volumio[814]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 19:03:46 volumio volumio[814]: info: [1711652626572] CoreMusicLibrary::Adding element USB PnP Sound Device Mar 28 19:03:46 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 19:03:46 volumio volumio[814]: Cannot find translation for source Bandcamp Discover Mar 28 19:03:46 volumio volumio[814]: Cannot find translation for source 80s80s Radio Mar 28 19:03:46 volumio volumio[814]: Cannot find translation for source Calm Radio Mar 28 19:03:46 volumio volumio[814]: Cannot find translation for source Mother Earth Radio Mar 28 19:03:46 volumio volumio[814]: Cannot find translation for source Podcast Mar 28 19:03:46 volumio volumio[814]: Cannot find translation for source Spotify Mar 28 19:03:46 volumio volumio[814]: Cannot find translation for source USB PnP Sound Device Mar 28 19:03:46 volumio volumio[814]: info: Checking against Known Cards name Mar 28 19:03:46 volumio volumio[814]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 19:03:46 volumio volumio[814]: info: [1711652626585] CoreMusicLibrary::Adding element Dummy Mar 28 19:03:46 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 19:03:46 volumio volumio[814]: Cannot find translation for source Bandcamp Discover Mar 28 19:03:46 volumio volumio[814]: Cannot find translation for source 80s80s Radio Mar 28 19:03:46 volumio volumio[814]: Cannot find translation for source Calm Radio Mar 28 19:03:46 volumio volumio[814]: Cannot find translation for source Mother Earth Radio Mar 28 19:03:46 volumio volumio[814]: Cannot find translation for source Podcast Mar 28 19:03:46 volumio volumio[814]: Cannot find translation for source Spotify Mar 28 19:03:46 volumio volumio[814]: Cannot find translation for source USB PnP Sound Device Mar 28 19:03:46 volumio volumio[814]: Cannot find translation for source Dummy Mar 28 19:03:46 volumio volumio[814]: info: Checking against Known Cards name Mar 28 19:03:46 volumio volumio[814]: info: Adding Server instance for streaming Mar 28 19:03:46 volumio volumio[814]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Mar 28 19:03:46 volumio volumio[814]: error: Hi Res Audio Failed Login: Missing Login Data Mar 28 19:03:46 volumio volumio[814]: info: Adding HIGHRESAUDIO REST API Endpoints Mar 28 19:03:46 volumio volumio[814]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Mar 28 19:03:46 volumio volumio[814]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Mar 28 19:03:46 volumio volumio[814]: info: Refreshing TIDAL token Mar 28 19:03:46 volumio volumio[814]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Mar 28 19:03:46 volumio volumio[814]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Mar 28 19:03:46 volumio volumio[814]: info: Stopping AccessToken refresher cron for QOBUZ Mar 28 19:03:46 volumio sudo[1561]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 28 19:03:46 volumio sudo[1561]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:46 volumio volumio[814]: info: AccessToken refresher cron started for QOBUZ Mar 28 19:03:46 volumio volumio[814]: info: Adding QOBUZ REST API Endpoints Mar 28 19:03:46 volumio volumio[814]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Mar 28 19:03:46 volumio sudo[1561]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:46 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:46 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:46 volumio volumio[814]: info: Successfully Added MyVolumio device Mar 28 19:03:46 volumio volumio[814]: info: Successfully Added MyVolumio device Mar 28 19:03:47 volumio volumio[814]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined Mar 28 19:03:47 volumio volumio[814]: info: Bluetooth name changed to Volumio Mar 28 19:03:47 volumio volumio[814]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined Mar 28 19:03:47 volumio volumio[814]: info: MPD Permissions set Mar 28 19:03:47 volumio sudo[1565]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Mar 28 19:03:47 volumio sudo[1565]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:47 volumio volumio[814]: info: camilladsp spawned new process with pid 1566, instance 1, run: true Mar 28 19:03:47 volumio systemd[1]: Started MyVolumio SSH Tunnel. Mar 28 19:03:47 volumio sudo[1565]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:47 volumio autossh[1575]: port set to 0, monitoring disabled Mar 28 19:03:47 volumio autossh[1575]: starting ssh (count 1) Mar 28 19:03:47 volumio autossh[1575]: ssh child pid is 1578 Mar 28 19:03:47 volumio volumio[814]: info: Successfully Updated MyVolumio device Mar 28 19:03:47 volumio volumio[814]: info: Successfully Updated MyVolumio device Mar 28 19:03:47 volumio volumio[814]: info: Remote SSH Started Mar 28 19:03:48 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:48 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:48 volumio volumiossh-tunnel[1574]: Warning: Permanently added '[us1.myvolumio.org]:2222,[162.243.167.188]:2222' (RSA) to the list of known hosts. Mar 28 19:03:48 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Mar 28 19:03:48 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Mar 28 19:03:48 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Mar 28 19:03:48 volumio volumio[814]: info: CoreCommandRouter::volumioGetBrowseSources Mar 28 19:03:48 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 28 19:03:48 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:48 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:48 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:48 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:48 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:48 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:48 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:48 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:48 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:48 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:48 volumio volumio[814]: 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 Total Clients: 18 Mar 28 19:03:48 volumio volumio[814]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 19 Mar 28 19:03:48 volumio volumio[814]: info: Starting Shairport Sync Mar 28 19:03:48 volumio volumio[814]: info: MRS: Found cast device: Chromecast-af70b46f0f9552f744405cb818a11caf Mar 28 19:03:48 volumio volumio[814]: info: Adding audio output: Mar 28 19:03:48 volumio sudo[1586]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 28 19:03:48 volumio sudo[1586]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:49 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 28 19:03:49 volumio systemd[1]: shairport-sync.service: Succeeded. Mar 28 19:03:49 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 28 19:03:49 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 28 19:03:49 volumio sudo[1586]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:49 volumio sudo[1590]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Mar 28 19:03:49 volumio sudo[1590]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:49 volumio volumio[814]: info: Access Token successfully retrieved Mar 28 19:03:49 volumio volumio[814]: info: Shairport-Sync Started Mar 28 19:03:49 volumio systemd[1]: Started Volumio Bluetooth Module. Mar 28 19:03:49 volumio sudo[1590]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:49 volumio sudo[1596]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* Mar 28 19:03:49 volumio sudo[1596]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:49 volumio volumiobt[1594]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory Mar 28 19:03:49 volumio sudo[1596]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:49 volumio volumio[814]: info: Volumio BT Module successfully started Mar 28 19:03:49 volumio volumio[814]: error: Upnp client error: Error: This socket has been ended by the other party Mar 28 19:03:49 volumio volumio[814]: info: TidalConnect service stoped! Mar 28 19:03:50 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Mar 28 19:03:50 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:50 volumio mpd[1554]: Mar 28 19:03 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 28 19:03:50 volumio systemd[1]: Started Music Player Daemon. Mar 28 19:03:50 volumio sudo[1544]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:50 volumio volumio[814]: Upnp client error: Error: This socket has been ended by the other party Mar 28 19:03:50 volumio volumio[814]: info: Successfully retrieved User Session From TIDAL Mar 28 19:03:50 volumio volumio[814]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Mar 28 19:03:50 volumio volumio[814]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Mar 28 19:03:50 volumio sudo[1612]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Mar 28 19:03:50 volumio sudo[1612]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:50 volumio volumio[814]: error: updateQueue error: null Mar 28 19:03:50 volumio systemd[1]: Started Volumio Tidal Connect Service. Mar 28 19:03:50 volumio sudo[1612]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:50 volumio volumio[814]: info: Successfully retrieved User Subscription From TIDAL Mar 28 19:03:50 volumio volumio[814]: info: Adding TIDAL to Browse Sources Mar 28 19:03:50 volumio volumio[814]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 28 19:03:50 volumio volumio[814]: info: [1711652630704] CoreMusicLibrary::Adding element TIDAL Mar 28 19:03:50 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 19:03:50 volumio volumio[814]: Cannot find translation for source Bandcamp Discover Mar 28 19:03:50 volumio volumio[814]: Cannot find translation for source 80s80s Radio Mar 28 19:03:50 volumio volumio[814]: Cannot find translation for source Calm Radio Mar 28 19:03:50 volumio volumio[814]: Cannot find translation for source Mother Earth Radio Mar 28 19:03:50 volumio volumio[814]: Cannot find translation for source Podcast Mar 28 19:03:50 volumio volumio[814]: Cannot find translation for source Spotify Mar 28 19:03:50 volumio volumio[814]: Cannot find translation for source USB PnP Sound Device Mar 28 19:03:50 volumio volumio[814]: Cannot find translation for source Dummy Mar 28 19:03:50 volumio volumio[814]: Cannot find translation for source TIDAL Mar 28 19:03:50 volumio sudo[1618]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio Mar 28 19:03:50 volumio sudo[1618]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 28 19:03:50 volumio volumio[814]: info: Stopping AccessToken refresher cron Mar 28 19:03:50 volumio volumiobt[1594]: pulseaudio: no process found Mar 28 19:03:50 volumio sudo[1618]: pam_unix(sudo:session): session closed for user root Mar 28 19:03:50 volumio volumio[814]: info: AccessToken refresher cron started Mar 28 19:03:50 volumio volumio[814]: info: Adding TIDAL REST API Endpoints Mar 28 19:03:50 volumio volumio[814]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Mar 28 19:03:51 volumio dbus-daemon[507]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.27' (uid=1000 pid=1623 comm="/usr/bin/pulseaudio --high-priority=true ") Mar 28 19:03:51 volumio systemd[1]: Starting RealtimeKit Scheduling Policy Service... Mar 28 19:03:51 volumio volumio[814]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 28 19:03:51 volumio dbus-daemon[507]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' Mar 28 19:03:51 volumio systemd[1]: Started RealtimeKit Scheduling Policy Service. Mar 28 19:03:51 volumio rtkit-daemon[1624]: Successfully called chroot. Mar 28 19:03:51 volumio rtkit-daemon[1624]: Successfully dropped privileges. Mar 28 19:03:51 volumio rtkit-daemon[1624]: Successfully limited resources. Mar 28 19:03:51 volumio rtkit-daemon[1624]: Running. Mar 28 19:03:51 volumio rtkit-daemon[1624]: Canary thread running. Mar 28 19:03:51 volumio rtkit-daemon[1624]: Watchdog thread running. Mar 28 19:03:51 volumio dbus-daemon[507]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.28' (uid=0 pid=1624 comm="/usr/lib/rtkit/rtkit-daemon ") Mar 28 19:03:51 volumio systemd[1]: Starting Authorization Manager... Mar 28 19:03:51 volumio volumio[814]: info: MRS: Getting audio outputs on start Mar 28 19:03:51 volumio volumio[814]: info: MRS: Requesting all other devices output Mar 28 19:03:51 volumio volumio[814]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 28 19:03:51 volumio polkitd[1627]: started daemon version 0.105 using authority implementation `local' version `0.105' Mar 28 19:03:51 volumio dbus-daemon[507]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Mar 28 19:03:51 volumio systemd[1]: Started Authorization Manager. Mar 28 19:03:51 volumio volumio[814]: info: Executing endpoint tc_getconfig Mar 28 19:03:51 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Mar 28 19:03:51 volumio vtcs[1614]: STARTING TidalConnect services, version: 1.3.0.19 Mar 28 19:03:52 volumio vtcs[1614]: STARTED TidalConnect services. Mar 28 19:03:52 volumio volumio[814]: info: Executing endpoint tc_connect Mar 28 19:03:52 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Mar 28 19:03:52 volumio volumio[814]: info: Connecting to TidalConnect Mar 28 19:03:52 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:03:52 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:03:52 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:52 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:03:52 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:03:52 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:03:52 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:03:52 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:52 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received tidalconnect Mar 28 19:03:52 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:03:52 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:03:52 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:52 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:03:52 volumio pulseaudio[1623]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Mar 28 19:03:52 volumio pulseaudio[1623]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Mar 28 19:03:52 volumio bluetoothd[622]: Endpoint registered: sender=:1.48 path=/MediaEndpoint/A2DPSource Mar 28 19:03:52 volumio bluetoothd[622]: Endpoint registered: sender=:1.48 path=/MediaEndpoint/A2DPSink Mar 28 19:03:52 volumio volumiobt[1594]: Applying permissions Mar 28 19:03:52 volumio volumiobt[1594]: Setting BT discoverable and pairable Mar 28 19:03:52 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:03:52 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:03:52 volumio pulseaudio[1623]: Failed to register as a handsfree audio agent with ofono: org.freedesktop.DBus.Error.ServiceUnknown: The name org.ofono was not provided by any .service files Mar 28 19:03:52 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:52 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received tidalconnect Mar 28 19:03:52 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 28 19:03:52 volumio kernel: Bluetooth: RFCOMM TTY layer initialized Mar 28 19:03:52 volumio kernel: Bluetooth: RFCOMM socket layer initialized Mar 28 19:03:52 volumio kernel: Bluetooth: RFCOMM ver 1.11 Mar 28 19:03:52 volumio volumiobt[1594]: [CHG] Controller B8:27:EB:B7:AC:4A Class: 0x0008041c Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [91B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [117B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [55B blob data] Mar 28 19:03:52 volumio volumiobt[1594]: [bluetooth]# -e power on Mar 28 19:03:52 volumio volumiobt[1594]: Invalid command in menu main: -e Mar 28 19:03:52 volumio volumiobt[1594]: Mar 28 19:03:52 volumio volumiobt[1594]: Use "help" for a list of available commands in a menu. Mar 28 19:03:52 volumio volumiobt[1594]: Use "menu " if you want to enter any submenu. Mar 28 19:03:52 volumio volumiobt[1594]: Use "back" if you want to return to menu main. Mar 28 19:03:52 volumio volumiobt[1594]: [bluetooth]# agent on Mar 28 19:03:52 volumio volumiobt[1594]: Agent is already registered Mar 28 19:03:52 volumio volumiobt[1594]: [bluetooth]# discoverable on Mar 28 19:03:52 volumio volumiobt[1594]: [bluetooth]# pairable on Mar 28 19:03:52 volumio volumiobt[1594]: [bluetooth]# agent NoInputNoOutput Mar 28 19:03:52 volumio volumiobt[1594]: Agent is already registered Mar 28 19:03:52 volumio volumiobt[1594]: [bluetooth]# default-agent Mar 28 19:03:52 volumio volumiobt[1594]: [bluetooth]# quit Mar 28 19:03:52 volumio volumiobt[1594]: [59B blob data] Mar 28 19:03:52 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 28 19:03:53 volumio volumio[814]: info: TidalConnect service started! Mar 28 19:03:53 volumio volumio[814]: info: BOOT COMPLETED Mar 28 19:03:53 volumio volumio[814]: [Metrics] CommandRouter: 106s 210.43ms Mar 28 19:03:53 volumio volumio[814]: info: CoreCommandRouter::volumiosetStartupVolume Mar 28 19:03:53 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 19:03:53 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 19:03:53 volumio volumio[814]: info: CoreCommandRouter::Close All Modals sent Mar 28 19:03:53 volumio volumio[814]: info: CoreCommandRouter::Close All Modals sent Mar 28 19:03:53 volumio volumio[814]: 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 Total Clients: 20 Mar 28 19:03:54 volumio volumio[814]: info: FusionDsp - ---- read samplerate, raw: Mar 28 19:03:54 volumio volumio[814]: error: FusionDsp - invalid sample rate Mar 28 19:03:54 volumio volumio[814]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Mar 28 19:03:54 volumio volumio[814]: info: FusionDsp - ---- read samplerate from file: 44100 Mar 28 19:03:54 volumio volumio[814]: info: FusionDsp - If filter freq >samplerate/2 then disable it Mar 28 19:03:54 volumio volumio[814]: info: FusionDsp - {"Reload":{"result":"Ok"}} Mar 28 19:03:54 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Mar 28 19:03:54 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 28 19:03:55 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Mar 28 19:03:55 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Mar 28 19:03:55 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:03:56 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 28 19:03:56 volumio volumio[814]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Mar 28 19:03:56 volumio volumio[814]: info: Listing playlists Mar 28 19:03:56 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Mar 28 19:03:56 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 28 19:03:56 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 28 19:03:56 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 28 19:03:58 volumio ntpd[646]: Soliciting pool server 2606:4700:f1::123 Mar 28 19:03:59 volumio volumio[814]: info: camilladsp spawned new process with pid 1686, instance 1, run: true Mar 28 19:04:03 volumio volumio[814]: info: VolumeController::SetAlsaVolume74 Mar 28 19:04:03 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:03 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:03 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:04:03 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:03 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:03 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:03 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 74 Mar 28 19:04:03 volumio volumio[814]: SPOTIFY: SPOTIFY VOLUME 100 Mar 28 19:04:03 volumio volumio[814]: SPOTIFY: VOLUMIO VOLUME 74 Mar 28 19:04:03 volumio volumio[814]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 28 19:04:03 volumio volumio[814]: info: Setting Spotify Volume from Volumio: 74 Mar 28 19:04:04 volumio volumio[814]: info: VolumeController::SetAlsaVolume65 Mar 28 19:04:04 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:04 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:04 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:04:04 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:04 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:04 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:04 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Mar 28 19:04:04 volumio volumio[814]: SPOTIFY: SPOTIFY VOLUME 74 Mar 28 19:04:04 volumio volumio[814]: SPOTIFY: VOLUMIO VOLUME 65 Mar 28 19:04:04 volumio volumio[814]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 28 19:04:04 volumio volumio[814]: info: Setting Spotify Volume from Volumio: 65 Mar 28 19:04:04 volumio volumio[814]: info: VolumeController::SetAlsaVolume51 Mar 28 19:04:04 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:04 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:04 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:04:04 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:04 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:04 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:04 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Mar 28 19:04:04 volumio volumio[814]: SPOTIFY: SPOTIFY VOLUME 65 Mar 28 19:04:04 volumio volumio[814]: SPOTIFY: VOLUMIO VOLUME 51 Mar 28 19:04:04 volumio volumio[814]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 28 19:04:04 volumio volumio[814]: info: Setting Spotify Volume from Volumio: 51 Mar 28 19:04:04 volumio volumio[814]: info: VolumeController::SetAlsaVolume60 Mar 28 19:04:04 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:04 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:04 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:04:04 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:04 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:04 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:04 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Mar 28 19:04:04 volumio volumio[814]: SPOTIFY: SPOTIFY VOLUME 51 Mar 28 19:04:04 volumio volumio[814]: SPOTIFY: VOLUMIO VOLUME 60 Mar 28 19:04:04 volumio volumio[814]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 28 19:04:04 volumio volumio[814]: info: Setting Spotify Volume from Volumio: 60 Mar 28 19:04:06 volumio volumio[814]: SPOTIFY: SETTING SPOTIFY VOLUME 60 Mar 28 19:04:06 volumio volumio[814]: info: Sending Spotify command with payload to local API: /player/volume Mar 28 19:04:06 volumio go-librespot[1094]: time="2024-03-28T19:04:06Z" level=debug msg="update volume to 39321/65535" Mar 28 19:04:06 volumio go-librespot[1094]: time="2024-03-28T19:04:06Z" level=debug msg="put connect state because VOLUME_CHANGED" Mar 28 19:04:06 volumio go-librespot[1094]: time="2024-03-28T19:04:06Z" level=trace msg="emitting websocket event: volume" Mar 28 19:04:06 volumio volumio[814]: SPOTIFY: received: {"type":"volume","data":{"value":60,"max":100}} Mar 28 19:04:06 volumio volumio[814]: SPOTIFY: RECEIVED SPOTIFY VOLUME 60 Mar 28 19:04:07 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 28 19:04:13 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Mar 28 19:04:13 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:13 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Mar 28 19:04:13 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:13 volumio volumio[814]: info: Currently active: 80s80s Mar 28 19:04:13 volumio volumio[814]: info: Stopping currently active service Mar 28 19:04:13 volumio volumio[814]: info: CoreCommandRouter::volumioStop Mar 28 19:04:13 volumio volumio[814]: info: CoreStateMachine::stop Mar 28 19:04:13 volumio volumio[814]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 19:04:13 volumio volumio[814]: info: CoreStateMachine::stPlaybackTimer Mar 28 19:04:13 volumio volumio[814]: info: CoreStateMachine::updateTrackBlock Mar 28 19:04:13 volumio volumio[814]: info: CorePlayQueue::getTrackBlock Mar 28 19:04:13 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:13 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:13 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:04:13 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:13 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:13 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:13 volumio volumio[814]: info: CoreStateMachine::serviceStop Mar 28 19:04:13 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:13 volumio volumio[814]: info: CoreCommandRouter::serviceStop Mar 28 19:04:13 volumio volumio[814]: info: ControllerMpd::stop Mar 28 19:04:13 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand stop Mar 28 19:04:13 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Mar 28 19:04:13 volumio volumio[814]: info: sendMpdCommand stop took 172 milliseconds Mar 28 19:04:13 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:04:13 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:13 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:13 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:04:13 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:13 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:13 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:13 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:13 volumio volumio[814]: verbose: STATE SERVICE {"status":"stop","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is1-ssl.mzstatic.com/image/thumb/Music/v4/9c/07/ec/9c07ec9a-954f-4e3a-45eb-363df21027ae/source/600x600bb.jpg","name":"Bananarama - I Heard a Rumour","title":"I Heard a Rumour","artist":"80s80s Real 80s Radio","album":"","streaming":true,"disableUiControls":true,"duration":"195","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Mar 28 19:04:13 volumio volumio[814]: verbose: CURRENT POSITION 0 Mar 28 19:04:13 volumio volumio[814]: info: CoreStateMachine::syncState stateService stop Mar 28 19:04:13 volumio volumio[814]: info: CoreStateMachine::syncState currentStatus stop Mar 28 19:04:13 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:13 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:13 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:13 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:13 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:13 volumio volumio[814]: info: No code Mar 28 19:04:13 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:13 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:13 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:13 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:13 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:13 volumio volumio[814]: info: TidalConnect Active Mar 28 19:04:13 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Mar 28 19:04:13 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:13 volumio volumio[814]: info: Currently active: 80s80s Mar 28 19:04:13 volumio volumio[814]: info: Setting Volatile state to tidalconnect Mar 28 19:04:13 volumio volumio[814]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 19:04:13 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:04:13 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:13 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:04:13 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:13 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:13 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:13 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:13 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received tidalconnect Mar 28 19:04:13 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:04:13 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:13 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:13 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:13 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:13 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:13 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received tidalconnect Mar 28 19:04:13 volumio volumio[814]: info: touch_display: Setting screensaver timeout to 60 seconds. Mar 28 19:04:13 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Mar 28 19:04:14 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Mar 28 19:04:14 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Mar 28 19:04:14 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Mar 28 19:04:14 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Mar 28 19:04:14 volumio volumio[814]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.lHoh5s4r4KXrweQahAvdWC5BBk33.95d071dca8379fc9cf0e8fc2110e9961.state.status' Mar 28 19:04:14 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 28 19:04:14 volumio volumio[814]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Mar 28 19:04:14 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Mar 28 19:04:14 volumio volumio[814]: info: Received Get System Version Mar 28 19:04:14 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 28 19:04:14 volumio volumio[814]: info: Received Get System Info Mar 28 19:04:14 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 28 19:04:14 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 28 19:04:14 volumio volumio[814]: info: Discovery: Getting this device information Mar 28 19:04:14 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Mar 28 19:04:14 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 28 19:04:14 volumio vtcs[1614]: [2024-03-28 19:04:14.795] [tisoc] [warning] [PlaybackControllerImpl.cpp:501] Illegal state:1 Mar 28 19:04:14 volumio volumio[814]: info: Pushing metadata Mar 28 19:04:14 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:04:14 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:14 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:14 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:14 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:14 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:14 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received tidalconnect Mar 28 19:04:14 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:04:14 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:14 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:14 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:14 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:14 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Mar 28 19:04:14 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received tidalconnect Mar 28 19:04:14 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:04:14 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:14 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:04:14 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:14 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:14 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:14 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:04:14 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:14 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:04:14 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:14 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:14 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:15 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Mar 28 19:04:15 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Mar 28 19:04:15 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Mar 28 19:04:15 volumio volumio[814]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.lHoh5s4r4KXrweQahAvdWC5BBk33.95d071dca8379fc9cf0e8fc2110e9961.state.status' Mar 28 19:04:15 volumio volumio[814]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.lHoh5s4r4KXrweQahAvdWC5BBk33.95d071dca8379fc9cf0e8fc2110e9961.state.status' Mar 28 19:04:15 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Mar 28 19:04:15 volumio volumio[814]: info: touch_display: Setting screensaver timeout to 0 seconds. Mar 28 19:04:15 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Mar 28 19:04:16 volumio volumio[814]: info: touch_display: Setting screensaver timeout to 0 seconds. Mar 28 19:04:16 volumio volumio[814]: info: Pushing metadata Mar 28 19:04:16 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:04:16 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:16 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:16 volumio vtcs[1614]: [2024-03-28 19:04:16.254] [tisoc] [warning] [audio_worker.cpp:326] Attempting to initialize a decoder without initial data! Mar 28 19:04:16 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:16 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:16 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:04:16 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:16 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:16 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:16 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:16 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:04:16 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:16 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:04:16 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:16 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:16 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:16 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:04:16 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:16 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:04:16 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:16 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:16 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:16 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:04:16 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:16 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:16 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:16 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:16 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:04:16 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:16 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:16 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:16 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:16 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Mar 28 19:04:16 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Mar 28 19:04:16 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Mar 28 19:04:16 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:04:16 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:16 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:04:16 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:16 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:16 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:17 volumio volumio[814]: info: touch_display: Setting screensaver timeout to 60 seconds. Mar 28 19:04:17 volumio volumio[814]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Mar 28 19:04:17 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:04:17 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:17 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:17 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:17 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:17 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:04:17 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:17 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:17 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:17 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:17 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:04:17 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:17 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:17 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:17 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:17 volumio volumio[814]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Mar 28 19:04:17 volumio volumio[814]: info: FusionDsp - ---- read samplerate from file: 44100 Mar 28 19:04:17 volumio volumio[814]: info: FusionDsp - If filter freq >samplerate/2 then disable it Mar 28 19:04:18 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Mar 28 19:04:18 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:04:18 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:18 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:18 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:18 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:18 volumio volumio[814]: info: CoreCommandRouter::servicePushState Mar 28 19:04:18 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:18 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:04:18 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:18 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:18 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:18 volumio volumio[814]: info: FusionDsp - {"Reload":{"result":"Ok"}} Mar 28 19:04:18 volumio volumio[814]: info: touch_display: Setting screensaver timeout to 0 seconds. Mar 28 19:04:18 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Mar 28 19:04:18 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Mar 28 19:04:18 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Mar 28 19:04:18 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Mar 28 19:04:18 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Mar 28 19:04:18 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Mar 28 19:04:18 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Mar 28 19:04:18 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Mar 28 19:04:21 volumio volumio[814]: info: VolumeController::SetAlsaVolume75 Mar 28 19:04:21 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:21 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:04:21 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:21 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:21 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:21 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Mar 28 19:04:21 volumio volumio[814]: SPOTIFY: SPOTIFY VOLUME 60 Mar 28 19:04:21 volumio volumio[814]: SPOTIFY: VOLUMIO VOLUME 75 Mar 28 19:04:21 volumio volumio[814]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 28 19:04:21 volumio volumio[814]: info: Setting Spotify Volume from Volumio: 75 Mar 28 19:04:22 volumio volumio[814]: info: VolumeController::SetAlsaVolume92 Mar 28 19:04:22 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:22 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:04:22 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:22 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:22 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:22 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 92 Mar 28 19:04:22 volumio volumio[814]: SPOTIFY: SPOTIFY VOLUME 75 Mar 28 19:04:22 volumio volumio[814]: SPOTIFY: VOLUMIO VOLUME 92 Mar 28 19:04:22 volumio volumio[814]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 28 19:04:22 volumio volumio[814]: info: Setting Spotify Volume from Volumio: 92 Mar 28 19:04:22 volumio volumio[814]: info: VolumeController::SetAlsaVolume96 Mar 28 19:04:22 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:22 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:04:22 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:22 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:22 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:22 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 96 Mar 28 19:04:22 volumio volumio[814]: SPOTIFY: SPOTIFY VOLUME 92 Mar 28 19:04:22 volumio volumio[814]: SPOTIFY: VOLUMIO VOLUME 96 Mar 28 19:04:22 volumio volumio[814]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 28 19:04:22 volumio volumio[814]: info: Setting Spotify Volume from Volumio: 96 Mar 28 19:04:22 volumio volumio[814]: info: VolumeController::SetAlsaVolume99 Mar 28 19:04:22 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:22 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:04:22 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:22 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:22 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:22 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 99 Mar 28 19:04:22 volumio volumio[814]: SPOTIFY: SPOTIFY VOLUME 96 Mar 28 19:04:22 volumio volumio[814]: SPOTIFY: VOLUMIO VOLUME 99 Mar 28 19:04:22 volumio volumio[814]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 28 19:04:22 volumio volumio[814]: info: Setting Spotify Volume from Volumio: 99 Mar 28 19:04:22 volumio volumio[814]: info: VolumeController::SetAlsaVolume100 Mar 28 19:04:23 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:23 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:04:23 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:23 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:23 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:23 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 28 19:04:23 volumio volumio[814]: SPOTIFY: SPOTIFY VOLUME 99 Mar 28 19:04:23 volumio volumio[814]: SPOTIFY: VOLUMIO VOLUME 100 Mar 28 19:04:23 volumio volumio[814]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 28 19:04:24 volumio volumio[814]: SPOTIFY: SETTING SPOTIFY VOLUME 99 Mar 28 19:04:24 volumio volumio[814]: info: Sending Spotify command with payload to local API: /player/volume Mar 28 19:04:24 volumio go-librespot[1094]: time="2024-03-28T19:04:24Z" level=debug msg="update volume to 64879/65535" Mar 28 19:04:24 volumio go-librespot[1094]: time="2024-03-28T19:04:24Z" level=debug msg="put connect state because VOLUME_CHANGED" Mar 28 19:04:24 volumio go-librespot[1094]: time="2024-03-28T19:04:24Z" level=trace msg="emitting websocket event: volume" Mar 28 19:04:24 volumio volumio[814]: SPOTIFY: received: {"type":"volume","data":{"value":99,"max":100}} Mar 28 19:04:24 volumio volumio[814]: SPOTIFY: RECEIVED SPOTIFY VOLUME 99 Mar 28 19:04:28 volumio volumio[814]: info: VolumeController::SetAlsaVolume36 Mar 28 19:04:28 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:28 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:04:28 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:29 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:29 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:29 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 36 Mar 28 19:04:29 volumio volumio[814]: SPOTIFY: SPOTIFY VOLUME 99 Mar 28 19:04:29 volumio volumio[814]: SPOTIFY: VOLUMIO VOLUME 36 Mar 28 19:04:29 volumio volumio[814]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 28 19:04:29 volumio volumio[814]: info: Setting Spotify Volume from Volumio: 36 Mar 28 19:04:30 volumio volumio[814]: info: VolumeController::SetAlsaVolume47 Mar 28 19:04:30 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:30 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:04:30 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:30 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:30 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:30 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 47 Mar 28 19:04:30 volumio volumio[814]: SPOTIFY: SPOTIFY VOLUME 36 Mar 28 19:04:30 volumio volumio[814]: SPOTIFY: VOLUMIO VOLUME 47 Mar 28 19:04:30 volumio volumio[814]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 28 19:04:30 volumio volumio[814]: info: Setting Spotify Volume from Volumio: 47 Mar 28 19:04:30 volumio volumio[814]: info: VolumeController::SetAlsaVolume52 Mar 28 19:04:30 volumio volumio[814]: info: CoreStateMachine::pushState Mar 28 19:04:30 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:04:30 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Mar 28 19:04:30 volumio volumio[814]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:04:30 volumio volumio[814]: info: MRS: Pushing multiroomSync output Mar 28 19:04:30 volumio volumio[814]: SPOTIFY: RECEIVED VOLUMIO VOLUME 52 Mar 28 19:04:30 volumio volumio[814]: SPOTIFY: SPOTIFY VOLUME 47 Mar 28 19:04:30 volumio volumio[814]: SPOTIFY: VOLUMIO VOLUME 52 Mar 28 19:04:30 volumio volumio[814]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 28 19:04:30 volumio volumio[814]: info: Setting Spotify Volume from Volumio: 52 Mar 28 19:04:32 volumio vtcs[1614]: [2024-03-28 19:04:31.999] [tisoc] [warning] [operation_curl.cpp:229] curl_easy_perform failed: Transferred a partial file - transfer closed with 524288 bytes remaining to read Mar 28 19:04:32 volumio vtcs[1614]: [2024-03-28 19:04:32.009] [tisoc] [warning] [http_stream_fetcher.cpp:153] Content-Range is missing from response! Mar 28 19:04:32 volumio volumio[814]: SPOTIFY: SETTING SPOTIFY VOLUME 52 Mar 28 19:04:32 volumio volumio[814]: info: Sending Spotify command with payload to local API: /player/volume Mar 28 19:04:32 volumio go-librespot[1094]: time="2024-03-28T19:04:32Z" level=debug msg="update volume to 34078/65535" Mar 28 19:04:32 volumio go-librespot[1094]: time="2024-03-28T19:04:32Z" level=debug msg="put connect state because VOLUME_CHANGED" Mar 28 19:04:32 volumio go-librespot[1094]: time="2024-03-28T19:04:32Z" level=trace msg="emitting websocket event: volume" Mar 28 19:04:32 volumio volumio[814]: SPOTIFY: received: {"type":"volume","data":{"value":52,"max":100}} Mar 28 19:04:32 volumio volumio[814]: SPOTIFY: RECEIVED SPOTIFY VOLUME 52 Mar 28 19:04:34 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 28 19:04:34 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 28 19:04:35 volumio volumio[949]: ....................................................................................................................................................................................................................................................................................++++ Mar 28 19:04:37 volumio volumio[949]: .....++++ Mar 28 19:04:37 volumio volumio[949]: e is 65537 (0x010001) Mar 28 19:04:37 volumio volumio[949]: writing RSA key Mar 28 19:04:39 volumio volumio[814]: info: CoreStateMachine::stop Mar 28 19:04:39 volumio volumio[814]: info: CoreStateMachine::serviceStop Mar 28 19:04:39 volumio volumio[814]: info: CoreCommandRouter::serviceStop Mar 28 19:04:39 volumio volumio[814]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 19:04:39 volumio volumio[814]: TypeError: Cannot read property 'then' of undefined Mar 28 19:04:39 volumio volumio[814]: at peppyScreensaver.onStop (/data/plugins/miscellanea/peppy_screensaver/index.js:178:43) Mar 28 19:04:39 volumio volumio[814]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30) Mar 28 19:04:39 volumio volumio[814]: at PluginManager.disableAndStopPlugin (/volumio/app/pluginmanager.js:1883:8) Mar 28 19:04:39 volumio volumio[814]: at CoreCommandRouter.disableAndStopPlugin (/volumio/app/index.js:1531:29) Mar 28 19:04:39 volumio volumio[814]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1356:47) Mar 28 19:04:39 volumio volumio[814]: at Socket.emit (events.js:315:20) Mar 28 19:04:39 volumio volumio[814]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Mar 28 19:04:39 volumio volumio[814]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Mar 28 19:04:39 volumio volumio[814]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 19:04:40 volumio vtcs[1614]: [2024-03-28 19:04:40.142] [tisoc] [warning] [PlaybackControllerImpl.cpp:501] Illegal state:0 Mar 28 19:04:42 volumio sudo[2046]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-03-28 19:03 Mar 28 19:04:42 volumio sudo[2046]: 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="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 21 Feb 2024 09:37:22 PM CET" VOLUMIO_VERSION="3.631" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fdd9dd1169c06c1ad0a30ddd24c91b6b"