-- Logs begin at Thu 2019-02-14 05:11:59 EST, end at Sat 2025-02-22 16:06:58 EST. -- Feb 22 16:06:04 main-system systemd-timedated[1047]: Changed local time to Sat Feb 22 16:06:04 2025 Feb 22 16:06:04 main-system sudo[1045]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:04 main-system volumio-time-update[672]: volumio-time-update-util: System time updated successfully. Feb 22 16:06:04 main-system systemd[1]: Started Volumio Time Update Utility. Feb 22 16:06:04 main-system systemd[1]: Reached target Multi-User System. Feb 22 16:06:04 main-system systemd[1]: Reached target Graphical Interface. Feb 22 16:06:04 main-system systemd[1]: Starting Update UTMP about System Runlevel Changes... Feb 22 16:06:04 main-system systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Feb 22 16:06:04 main-system systemd[1]: Started Update UTMP about System Runlevel Changes. Feb 22 16:06:04 main-system systemd[1]: Startup finished in 12.949s (kernel) + 22.579s (userspace) = 35.528s. Feb 22 16:06:05 main-system volumio[861]: info: Loading plugin "ytmusic"... Feb 22 16:06:05 main-system volumio-remote-updater[649]: [2025-02-22 16:06:05] [connect] Successful connection Feb 22 16:06:06 main-system volumio[861]: info: Loading plugin "autostart"... Feb 22 16:06:06 main-system volumio[861]: info: Applying required configuration parameters for plugin autostart Feb 22 16:06:06 main-system volumio[861]: info: AutoStart - onVolumioStart - read config.json Feb 22 16:06:06 main-system volumio[861]: info: Loading plugin "now_playing"... Feb 22 16:06:07 main-system volumio[861]: info: Loading plugin "outputs"... Feb 22 16:06:07 main-system volumio[861]: info: Loading plugin "albumart"... Feb 22 16:06:07 main-system volumio[861]: info: Plugin example_plugin is not enabled Feb 22 16:06:07 main-system volumio[861]: info: Loading plugin "inputs"... Feb 22 16:06:07 main-system volumio[861]: info: Loading plugin "updater_comm"... Feb 22 16:06:08 main-system volumio[861]: info: Plugin mpdemulation is not enabled Feb 22 16:06:08 main-system volumio[861]: info: Loading plugin "rest_api"... Feb 22 16:06:08 main-system volumio[861]: info: Loading plugin "websocket"... Feb 22 16:06:08 main-system volumio[861]: info: Starting Socket.io Server version 2.3.0 Feb 22 16:06:08 main-system volumio[861]: info: Loading plugin "fusiondsp"... Feb 22 16:06:08 main-system volumio[861]: Forking 3 albumart workers Feb 22 16:06:08 main-system volumio[861]: info: Applying required configuration parameters for plugin fusiondsp Feb 22 16:06:08 main-system volumio[861]: info: Loading plugin "dmd2_music"... Feb 22 16:06:08 main-system volumio[861]: Starting albumart workers Feb 22 16:06:08 main-system volumio[861]: Starting albumart workers Feb 22 16:06:08 main-system volumio[861]: Starting albumart workers Feb 22 16:06:09 main-system volumio[861]: info: Plugin minidlna is not enabled Feb 22 16:06:09 main-system volumio[861]: info: Loading plugin "volusonic"... Feb 22 16:06:10 main-system volumio[861]: info: Applying required configuration parameters for plugin volusonic Feb 22 16:06:10 main-system volumio[861]: info: Loading plugin "backup_restore"... Feb 22 16:06:10 main-system volumio[861]: info: Applying required configuration parameters for plugin backup_restore Feb 22 16:06:10 main-system volumio[861]: info: Loading plugin "music_services_shield"... Feb 22 16:06:11 main-system volumio[861]: info: Applying required configuration parameters for plugin music_services_shield Feb 22 16:06:11 main-system volumio[861]: info: Loading plugin "Systeminfo"... Feb 22 16:06:11 main-system volumio[861]: info: Loading plugin "randomizer"... Feb 22 16:06:11 main-system volumio[861]: info: Applying required configuration parameters for plugin randomizer Feb 22 16:06:11 main-system volumio[861]: info: Loading plugin "touch_display"... Feb 22 16:06:12 main-system volumio[861]: info: Applying required configuration parameters for plugin touch_display Feb 22 16:06:12 main-system volumio[861]: info: Loading i18n strings for locale en Feb 22 16:06:12 main-system volumio[861]: info: Plugin volusonic has duplicated i18n key SAVE. It is ignored. Feb 22 16:06:12 main-system volumio[861]: Updating browse sources language Feb 22 16:06:12 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 22 16:06:12 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 22 16:06:12 main-system volumio[861]: info: CoreCommandRouter::initPlayerControls Feb 22 16:06:12 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:12 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:12 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:12 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:12 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:12 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:12 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:12 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:12 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 22 16:06:12 main-system volumio[861]: Express server listening on port 3000 Feb 22 16:06:12 main-system volumio[861]: [Metrics] WebUI: 19s 751.75ms Feb 22 16:06:12 main-system volumio[861]: info: CoreStateMachine::resetVolumioState Feb 22 16:06:12 main-system volumio[861]: info: CoreStateMachine::getcurrentVolume Feb 22 16:06:12 main-system volumio[861]: info: CoreCommandRouter::volumioRetrievevolume Feb 22 16:06:12 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 16:06:12 main-system volumio[861]: info: Volumio Network Manager: Network status updated: 0 Feb 22 16:06:12 main-system volumio[861]: info: CoreStateMachine::pushState Feb 22 16:06:12 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:12 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:06:12 main-system volumio[861]: info: CoreCommandRouter::volumioPushState Feb 22 16:06:12 main-system volumio[861]: info: CoreStateMachine::updateTrackBlock Feb 22 16:06:12 main-system volumio[861]: info: CorePlayQueue::getTrackBlock Feb 22 16:06:12 main-system volumio[861]: info: CoreCommandRouter::volumioRetrievevolume Feb 22 16:06:12 main-system volumio[861]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Feb 22 16:06:12 main-system volumio[861]: info: Reloading queue from file Feb 22 16:06:12 main-system volumio[861]: info: CoreStateMachine::pushState Feb 22 16:06:12 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:12 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:06:12 main-system volumio[861]: info: CoreCommandRouter::volumioPushState Feb 22 16:06:12 main-system volumio[861]: info: CoreStateMachine::setRepeat true single undefined Feb 22 16:06:12 main-system volumio[861]: info: CoreStateMachine::pushState Feb 22 16:06:12 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:12 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:06:12 main-system volumio[861]: info: CoreCommandRouter::volumioPushState Feb 22 16:06:12 main-system volumio[861]: info: CoreStateMachine::setRandom true Feb 22 16:06:12 main-system volumio[861]: info: CoreStateMachine::pushState Feb 22 16:06:12 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:12 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:06:12 main-system volumio[861]: info: CoreCommandRouter::volumioPushState Feb 22 16:06:12 main-system volumio[861]: info: Setting Device type: Raspberry PI Feb 22 16:06:12 main-system volumio[861]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Feb 22 16:06:12 main-system volumio[861]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Feb 22 16:06:12 main-system volumio[861]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Feb 22 16:06:12 main-system volumio[861]: info: Completed loading Core Plugins Feb 22 16:06:12 main-system volumio[861]: info: Preparing to generate the ALSA configuration file Feb 22 16:06:12 main-system volumio[861]: info: Discovery: adding 39de326e-0c8d-49e6-ad8a-8e06195d9e03 Feb 22 16:06:12 main-system volumio[861]: info: Discovery: Found device Main System Feb 22 16:06:12 main-system volumio[861]: info: CoreCommandRouter::volumioGetState Feb 22 16:06:12 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:12 main-system volumio[861]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Feb 22 16:06:12 main-system volumio[861]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Feb 22 16:06:12 main-system volumio[861]: info: Reading ALSA contributions from plugins. Feb 22 16:06:12 main-system volumio[861]: info: Asound.conf file unchanged, so no further update is needed Feb 22 16:06:12 main-system volumio[861]: info: Output device has changed, restarting MPD Feb 22 16:06:12 main-system sudo[1139]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 22 16:06:12 main-system sudo[1139]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:12 main-system sudo[1139]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:12 main-system volumio[861]: info: Output device has changed, restarting Shairport Sync Feb 22 16:06:12 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:12 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 16:06:12 main-system sudo[1142]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 22 16:06:12 main-system sudo[1142]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:13 main-system systemd[1]: musicservicesshield.service: Succeeded. Feb 22 16:06:13 main-system systemd[1]: Stopped Shield Volumio Music Services in the User CPU Set. Feb 22 16:06:13 main-system systemd[1]: Stopping Shield Volumio Music Services in the User CPU Set... Feb 22 16:06:13 main-system systemd[1]: Stopping Music Player Daemon... Feb 22 16:06:13 main-system volumio[861]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 22 16:06:13 main-system volumio[861]: info: ___________ START PLUGINS ___________ Feb 22 16:06:13 main-system volumio[861]: info: ControllerMpd::onStart: Initializing MPD Feb 22 16:06:13 main-system volumio[861]: info: Creating MPD Configuration file Feb 22 16:06:13 main-system sudo[1148]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 22 16:06:13 main-system sudo[1148]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 22 16:06:13 main-system volumio[861]: info: [1740258373082] CoreMusicLibrary::Adding element Media Servers Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 22 16:06:13 main-system sudo[1148]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:13 main-system sudo[1151]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 22 16:06:13 main-system sudo[1151]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 16:06:13 main-system systemd[1]: mpd.service: Succeeded. Feb 22 16:06:13 main-system systemd[1]: Stopped Music Player Daemon. Feb 22 16:06:13 main-system volumio[861]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 16:06:13 main-system volumio[861]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 22 16:06:13 main-system volumio[861]: info: [1740258373186] CoreMusicLibrary::Adding element Last_100 Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 22 16:06:13 main-system volumio[861]: info: [1740258373188] CoreMusicLibrary::Adding element Webradio Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 22 16:06:13 main-system volumio[861]: info: Initializing BBC Radios Feb 22 16:06:13 main-system systemd[1]: Starting Music Player Daemon... Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 16:06:13 main-system volumio[861]: info: Adding Calm Radio to Browse Sources Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 22 16:06:13 main-system volumio[861]: info: [1740258373272] CoreMusicLibrary::Adding element Calm Radio Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 22 16:06:13 main-system volumio[861]: Cannot find translation for source Calm Radio Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 22 16:06:13 main-system volumio[861]: info: [1740258373280] CoreMusicLibrary::Adding element Mixcloud Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 22 16:06:13 main-system volumio[861]: Cannot find translation for source Calm Radio Feb 22 16:06:13 main-system volumio[861]: Cannot find translation for source Mixcloud Feb 22 16:06:13 main-system volumio[861]: info: Creating Spotify config file Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:13 main-system sudo[1156]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 22 16:06:13 main-system sudo[1156]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 22 16:06:13 main-system volumio[861]: info: [1740258373305] CoreMusicLibrary::Adding element YouTube2 Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 22 16:06:13 main-system volumio[861]: Cannot find translation for source Calm Radio Feb 22 16:06:13 main-system volumio[861]: Cannot find translation for source Mixcloud Feb 22 16:06:13 main-system volumio[861]: Cannot find translation for source YouTube2 Feb 22 16:06:13 main-system sudo[1156]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 22 16:06:13 main-system volumio[861]: info: [1740258373341] CoreMusicLibrary::Adding element YouTube Music Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 22 16:06:13 main-system volumio[861]: Cannot find translation for source Calm Radio Feb 22 16:06:13 main-system volumio[861]: Cannot find translation for source Mixcloud Feb 22 16:06:13 main-system volumio[861]: Cannot find translation for source YouTube2 Feb 22 16:06:13 main-system volumio[861]: Cannot find translation for source YouTube Music Feb 22 16:06:13 main-system volumio[861]: info: AutoStart - onStart Feb 22 16:06:13 main-system volumio[861]: info: [now-playing] ConfigUpdater: config is up to date. Feb 22 16:06:13 main-system volumio[861]: info: Loading i18n strings for locale en Feb 22 16:06:13 main-system volumio[861]: info: Plugin volusonic has duplicated i18n key SAVE. It is ignored. Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:13 main-system volumio[861]: info: FusionDsp - mixtype--------------------- Software Feb 22 16:06:13 main-system volumio[861]: info: Stopping AccessToken refresher cron for DMD2 Music Feb 22 16:06:13 main-system volumio[861]: info: AccessToken refresher cron started for DMD2 Music Feb 22 16:06:13 main-system volumio[861]: info: Loading i18n strings for locale en Feb 22 16:06:13 main-system volumio[861]: info: Plugin volusonic has duplicated i18n key SAVE. It is ignored. Feb 22 16:06:13 main-system volumio[861]: Updating browse sources language Feb 22 16:06:13 main-system volumio[861]: Cannot find translation for source Calm Radio Feb 22 16:06:13 main-system volumio[861]: Cannot find translation for source Mixcloud Feb 22 16:06:13 main-system volumio[861]: Cannot find translation for source YouTube2 Feb 22 16:06:13 main-system volumio[861]: Cannot find translation for source YouTube Music Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 22 16:06:13 main-system volumio[861]: Cannot find translation for source Calm Radio Feb 22 16:06:13 main-system volumio[861]: Cannot find translation for source Mixcloud Feb 22 16:06:13 main-system volumio[861]: Cannot find translation for source YouTube2 Feb 22 16:06:13 main-system volumio[861]: Cannot find translation for source YouTube Music Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 22 16:06:13 main-system volumio[861]: info: [1740258373461] CoreMusicLibrary::Adding element Volusonic Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 22 16:06:13 main-system volumio[861]: Cannot find translation for source Calm Radio Feb 22 16:06:13 main-system volumio[861]: Cannot find translation for source Mixcloud Feb 22 16:06:13 main-system volumio[861]: Cannot find translation for source YouTube2 Feb 22 16:06:13 main-system volumio[861]: Cannot find translation for source YouTube Music Feb 22 16:06:13 main-system volumio[861]: Cannot find translation for source Volusonic Feb 22 16:06:13 main-system volumio[861]: info: Loading i18n strings for locale en Feb 22 16:06:13 main-system volumio[861]: info: Plugin volusonic has duplicated i18n key SAVE. It is ignored. Feb 22 16:06:13 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 22 16:06:13 main-system volumio[861]: info: Volumio Calling Home Feb 22 16:06:13 main-system sudo[1198]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/moveallprocesses.sh Feb 22 16:06:13 main-system sudo[1198]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:13 main-system volumio[861]: info: Preparing to generate the ALSA configuration file Feb 22 16:06:13 main-system sudo[1212]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Feb 22 16:06:13 main-system sudo[1212]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:13 main-system sudo[1214]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Feb 22 16:06:13 main-system sudo[1214]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:13 main-system sudo[1218]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Feb 22 16:06:13 main-system sudo[1218]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:13 main-system systemd[1]: Reloading. Feb 22 16:06:14 main-system mpd[1171]: Feb 22 16:06 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 22 16:06:14 main-system volumio[861]: info: [now-playing] App is listening on port 4004. Feb 22 16:06:14 main-system volumio[861]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Feb 22 16:06:14 main-system volumio[861]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Feb 22 16:06:14 main-system volumio[861]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Feb 22 16:06:14 main-system volumio[861]: info: Reading ALSA contributions from plugins. Feb 22 16:06:14 main-system volumio[861]: info: touch_display: Backlight interface detected. Feb 22 16:06:14 main-system volumio[861]: info: MPD Permissions set Feb 22 16:06:14 main-system volumio[861]: info: MPD Permissions set Feb 22 16:06:14 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 22 16:06:14 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 22 16:06:14 main-system volumio[861]: info: Discovery: Getting this device information Feb 22 16:06:14 main-system volumio[861]: info: CoreCommandRouter::volumioGetState Feb 22 16:06:14 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:14 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 22 16:06:14 main-system volumio[861]: info: Volumio called home Feb 22 16:06:14 main-system sudo[1198]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:14 main-system volumio[861]: info: Spotify config file written Feb 22 16:06:14 main-system 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. Feb 22 16:06:14 main-system sudo[1242]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 22 16:06:14 main-system sudo[1242]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:14 main-system volumio[861]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 22 16:06:14 main-system volumio[861]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 22 16:06:14 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:14 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 16:06:14 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:14 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:14 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:14 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:14 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:14 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:14 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:14 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:14 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:14 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 16:06:14 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:14 main-system volumio[861]: info: No need to fix Spotify hosts Feb 22 16:06:14 main-system sudo[1254]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/addservice.sh Feb 22 16:06:14 main-system sudo[1254]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:14 main-system volumio[861]: verbose: New Socket.io Connection to 10.0.0.140:3000 from 10.0.0.172 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 4 Feb 22 16:06:14 main-system volumio[861]: info: touch_display: Raspberry Pi Foundation touch screen detected. Feb 22 16:06:14 main-system systemd[1]: Started Music Player Daemon. Feb 22 16:06:14 main-system sudo[1151]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:14 main-system sudo[1142]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:14 main-system sudo[1218]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:14 main-system systemd[1]: Reloading. Feb 22 16:06:14 main-system sudo[1259]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Feb 22 16:06:14 main-system sudo[1259]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:14 main-system sudo[1259]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:14 main-system sudo[1262]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+w /sys/class/backlight/rpi_backlight/brightness Feb 22 16:06:14 main-system sudo[1262]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:14 main-system volumio[861]: info: Starting Shairport Sync Feb 22 16:06:14 main-system sudo[1262]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:14 main-system volumio[861]: info: Starting Shairport Sync Feb 22 16:06:14 main-system sudo[1273]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 22 16:06:14 main-system sudo[1273]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:14 main-system volumio[861]: info: Starting Shairport Sync Feb 22 16:06:14 main-system sudo[1281]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 22 16:06:14 main-system sudo[1281]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:14 main-system volumio[861]: info: CoreCommandRouter::volumioGetState Feb 22 16:06:14 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:14 main-system sudo[1283]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 22 16:06:14 main-system sudo[1283]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:14 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 22 16:06:14 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 22 16:06:14 main-system volumio[861]: info: CoreCommandRouter::volumioGetState Feb 22 16:06:14 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:14 main-system volumio[861]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Feb 22 16:06:14 main-system volumio[861]: info: touch_display: systemctl daemon-reload succeeded. Feb 22 16:06:14 main-system sudo[1287]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Feb 22 16:06:14 main-system sudo[1287]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:14 main-system 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. Feb 22 16:06:15 main-system volumio[861]: info: touch_display: File permissions for backlight brightness control set. Feb 22 16:06:15 main-system volumio[861]: info: Asound.conf file unchanged, so no further update is needed Feb 22 16:06:15 main-system volumio[861]: info: Output device has changed, restarting MPD Feb 22 16:06:15 main-system sudo[1292]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 22 16:06:15 main-system sudo[1292]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:15 main-system sudo[1292]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:15 main-system volumio[861]: info: Output device has changed, restarting Shairport Sync Feb 22 16:06:15 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:15 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 16:06:15 main-system sudo[1295]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 22 16:06:15 main-system sudo[1295]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:15 main-system volumio[861]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 22 16:06:15 main-system volumio[861]: error: MPD error: The expression evaluated to a falsy value: Feb 22 16:06:15 main-system volumio[861]: assert.ok(self.idling) Feb 22 16:06:15 main-system volumio[861]: error: The expression evaluated to a falsy value: Feb 22 16:06:15 main-system volumio[861]: assert.ok(self.idling) Feb 22 16:06:15 main-system volumio[861]: info: MPD running with PID1171 Feb 22 16:06:15 main-system volumio[861]: ,establishing connection Feb 22 16:06:15 main-system volumio[861]: error: updateQueue error: null Feb 22 16:06:15 main-system volumio[861]: info: MPD Permissions set Feb 22 16:06:15 main-system volumio[861]: error: updateQueue error: null Feb 22 16:06:15 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:15 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:15 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:15 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:15 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:15 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:15 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:15 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:15 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 16:06:15 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:15 main-system volumio[861]: info: Starting Shairport Sync Feb 22 16:06:15 main-system sudo[1308]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 22 16:06:15 main-system sudo[1308]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:15 main-system sudo[1214]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:15 main-system volumio[861]: info: camilladsp spawned new process with pid 1316, instance 1, run: true Feb 22 16:06:15 main-system volumio[861]: info: camilladsp service started and running in background, instance 1 Feb 22 16:06:15 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:15 main-system systemd[1]: Stopping Music Player Daemon... Feb 22 16:06:15 main-system systemd[1]: Started Volumio Kiosk. Feb 22 16:06:15 main-system systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 22 16:06:15 main-system sudo[1287]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:15 main-system systemd[1]: Started go-librespot Daemon. Feb 22 16:06:15 main-system sudo[1242]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:15 main-system go-librespot[1324]: go-librespot daemon starting... Feb 22 16:06:15 main-system systemd[1]: shairport-sync.service: Succeeded. Feb 22 16:06:15 main-system systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 22 16:06:15 main-system systemd[1]: mpd.service: Succeeded. Feb 22 16:06:15 main-system systemd[1]: Stopped Music Player Daemon. Feb 22 16:06:15 main-system volumio[861]: info: FusionDsp - AAAAAAAAAAAAAA-> 44100 48000 88200 96000 <-AAAAAAAAAAAAA Feb 22 16:06:15 main-system sudo[1212]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:15 main-system volumio[861]: info: FusionDsp loaded Feb 22 16:06:15 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 22 16:06:15 main-system sudo[1349]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Feb 22 16:06:15 main-system sudo[1349]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:15 main-system systemd[1]: Starting Music Player Daemon... Feb 22 16:06:15 main-system volumio[861]: info: FusionDsp - Reporting Fusion DSP Enabled Feb 22 16:06:15 main-system volumio[861]: info: Adding Signal Path Element [object Object] Feb 22 16:06:15 main-system volumio[861]: info: Adding fusiondspeq DSP Signal Path Element Feb 22 16:06:15 main-system volumio[861]: info: FusionDsp - ---- installed callbackRead Feb 22 16:06:15 main-system volumio[861]: info: Volumio Network Manager: Network status updated: 1 Feb 22 16:06:15 main-system volumio[861]: info: touch_display: systemctl stop getty@tty1.service succeeded. Feb 22 16:06:15 main-system volumio[861]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Feb 22 16:06:15 main-system volumio[861]: info: touch_display: Volumio Kiosk started. Feb 22 16:06:15 main-system systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 22 16:06:15 main-system volumio[861]: info: CoreCommandRouter::volumioGetState Feb 22 16:06:15 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:15 main-system sudo[1283]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:15 main-system volumio[861]: info: touch_display: systemctl disable getty@tty1.service succeeded. Feb 22 16:06:15 main-system volumio[861]: info: FusionDsp - If filter freq >samplerate/2 then disable it Feb 22 16:06:15 main-system sudo[1273]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:15 main-system sudo[1281]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:15 main-system sudo[1308]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:15 main-system volumio[861]: info: CoreCommandRouter::volumioGetState Feb 22 16:06:15 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:15 main-system volumio[861]: info: Shairport-Sync Started Feb 22 16:06:15 main-system volumio[861]: Error adding Membership: Error: addMembership EINVAL Feb 22 16:06:15 main-system volumio[861]: info: Shairport-Sync Started Feb 22 16:06:15 main-system volumio[861]: info: Shairport-Sync Started Feb 22 16:06:15 main-system volumio[861]: error: FusionDsp - WebSocket error: [object Object] Feb 22 16:06:15 main-system volumio[861]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Feb 22 16:06:15 main-system volumio[861]: info: Shairport-Sync Started Feb 22 16:06:15 main-system sudo[1350]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 22 16:06:15 main-system sudo[1350]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:15 main-system sudo[1350]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:15 main-system systemd[1]: Started FusionDsp Daemon. Feb 22 16:06:15 main-system volumio[861]: info: touch_display: X display number found: 0 Feb 22 16:06:15 main-system sudo[1349]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:15 main-system volumio[861]: info: touch_display: X display number found: 0 Feb 22 16:06:15 main-system volumio[861]: info: touch_display: X display number found: 0 Feb 22 16:06:16 main-system volumio[861]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 22 16:06:16 main-system volumio[861]: info: CoreCommandRouter::volumioRetrievevolume Feb 22 16:06:16 main-system volumio[861]: info: CoreCommandRouter::volumioGetState Feb 22 16:06:16 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:16 main-system volumio[861]: info: CoreStateMachine::pushState Feb 22 16:06:16 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:16 main-system volumio[861]: info: CoreCommandRouter::volumioPushState Feb 22 16:06:16 main-system volumio[861]: info: touch_display: X display number found: 0 Feb 22 16:06:16 main-system startx[1318]: X.Org X Server 1.20.4 Feb 22 16:06:16 main-system startx[1318]: X Protocol Version 11, Revision 0 Feb 22 16:06:16 main-system startx[1318]: Build Operating System: Linux 5.4.0-109-generic armv8l Raspbian Feb 22 16:06:16 main-system startx[1318]: Current Operating System: Linux main-system 6.6.62-v7l+ #1816 SMP Mon Nov 18 15:33:33 GMT 2024 armv7l Feb 22 16:06:16 main-system startx[1318]: Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_headphones=0 cgroup_disable=memory numa_policy=interleave snd_bcm2835.enable_headphones=1 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=800 bcm2708_fb.fbheight=480 bcm2708_fb.fbswap=1 smsc95xx.macaddr=DC:A6:32:94:4D:85 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=UUID=ce08a6e2-dec6-4d2e-8d73-ee28c8b309a0 imgfile=/volumio_current.sqsh bootpart=UUID=781E-BEF0 datapart=UUID=a10bd615-b13f-43a6-8e15-846545e24829 uuidconfig=cmdline.txt pcie_aspm=off pci=pcie_bus_safe rootwait bootdelay=7 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 nodebug use_kmsg=no Feb 22 16:06:16 main-system startx[1318]: Build Date: 04 April 2023 07:50:56AM Feb 22 16:06:16 main-system startx[1318]: xorg-server 2:1.20.4-1+rpt4+deb10u9 (https://www.debian.org/support) Feb 22 16:06:16 main-system startx[1318]: Current version of pixman: 0.36.0 Feb 22 16:06:16 main-system startx[1318]: Before reporting problems, check http://wiki.x.org Feb 22 16:06:16 main-system startx[1318]: to make sure that you have the latest version. Feb 22 16:06:16 main-system startx[1318]: Markers: (--) probed, (**) from config file, (==) default setting, Feb 22 16:06:16 main-system startx[1318]: (++) from command line, (!!) notice, (II) informational, Feb 22 16:06:16 main-system startx[1318]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Feb 22 16:06:16 main-system startx[1318]: (==) Log file: "/var/log/Xorg.0.log", Time: Sat Feb 22 16:06:16 2025 Feb 22 16:06:16 main-system startx[1318]: (==) Using config directory: "/etc/X11/xorg.conf.d" Feb 22 16:06:16 main-system startx[1318]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Feb 22 16:06:16 main-system volumio[861]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Feb 22 16:06:16 main-system volumio[861]: info: touch_display: X display number found: 0 Feb 22 16:06:16 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 22 16:06:16 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 22 16:06:16 main-system volumio[861]: info: Discovery: Getting this device information Feb 22 16:06:16 main-system volumio[861]: info: CoreCommandRouter::volumioGetState Feb 22 16:06:16 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:16 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 22 16:06:16 main-system mpd[1370]: Feb 22 16:06 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 22 16:06:16 main-system systemd[1]: Started Music Player Daemon. Feb 22 16:06:16 main-system sudo[1295]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:16 main-system volumio[861]: error: updateQueue error: null Feb 22 16:06:16 main-system systemd[1]: Starting Shield Volumio Music Services in the User CPU Set... Feb 22 16:06:16 main-system volumio[861]: info: Completed starting Core Plugins Feb 22 16:06:16 main-system volumio[861]: info: ------------------------------------------- Feb 22 16:06:16 main-system volumio[861]: info: ----- MyVolumio plugins startup ---- Feb 22 16:06:16 main-system volumio[861]: info: ------------------------------------------- Feb 22 16:06:16 main-system volumio[861]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 22 16:06:16 main-system go-librespot[1324]: time="2025-02-22T16:06:16-05:00" level=info msg="running go-librespot 0.2.0" Feb 22 16:06:16 main-system go-librespot[1324]: time="2025-02-22T16:06:16-05:00" level=debug msg="app state loaded" Feb 22 16:06:16 main-system go-librespot[1324]: time="2025-02-22T16:06:16-05:00" level=debug msg="stored credentials not found" Feb 22 16:06:16 main-system go-librespot[1324]: time="2025-02-22T16:06:16-05:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 22 16:06:17 main-system volumio[1399]: cset: --> shielding system active with Feb 22 16:06:17 main-system volumio[1399]: cset: "system" cpuset of CPUSPEC(1-3) with 123 tasks running Feb 22 16:06:17 main-system volumio[1399]: cset: "user" cpuset of CPUSPEC(0) with 3 tasks running Feb 22 16:06:17 main-system systemd[1]: Started Shield Volumio Music Services in the User CPU Set. Feb 22 16:06:17 main-system systemd[1]: Reloading. Feb 22 16:06:17 main-system go-librespot[1324]: time="2025-02-22T16:06:17-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Feb 22 16:06:17 main-system go-librespot[1324]: time="2025-02-22T16:06:17-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 22 16:06:17 main-system go-librespot[1324]: time="2025-02-22T16:06:17-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 22 16:06:17 main-system go-librespot[1324]: time="2025-02-22T16:06:17-05:00" level=info msg="zeroconf server listening on port 43117" Feb 22 16:06:17 main-system 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. Feb 22 16:06:17 main-system systemd[1]: systemd-fsckd.service: Succeeded. Feb 22 16:06:17 main-system sudo[1254]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:17 main-system volumio[861]: info: succeeded Feb 22 16:06:18 main-system volumio[861]: info: go-librespot daemon successfully initialized Feb 22 16:06:18 main-system volumio[861]: info: touch_display: Setting screensaver timeout to 120 seconds. Feb 22 16:06:19 main-system sudo[1460]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 22 16:06:19 main-system sudo[1460]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:19 main-system sudo[1460]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:19 main-system sudo[1463]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 22 16:06:19 main-system sudo[1463]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:19 main-system sudo[1463]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:19 main-system volumio[861]: verbose: New Socket.io Connection to 10.0.0.140 from 10.0.0.172 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_6) AppleWebKit/605.1.15 (KHTML, like Gecko) Engine version: 3 Transport: polling Total Clients: 6 Feb 22 16:06:19 main-system systemd[1]: systemd-hostnamed.service: Succeeded. Feb 22 16:06:19 main-system volumio[861]: info: CoreCommandRouter::volumioGetVisibleSources Feb 22 16:06:19 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 22 16:06:19 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 22 16:06:19 main-system volumio[861]: info: CoreCommandRouter::volumioGetState Feb 22 16:06:19 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:19 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Feb 22 16:06:19 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 22 16:06:19 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 22 16:06:19 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 22 16:06:20 main-system volumio[861]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 22 16:06:20 main-system sudo[1503]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 22 16:06:20 main-system sudo[1503]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:20 main-system sudo[1503]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:20 main-system sudo[1506]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 22 16:06:20 main-system sudo[1506]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:20 main-system sudo[1506]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:20 main-system volumio[861]: verbose: New Socket.io Connection to 10.0.0.140 from 10.0.0.172 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_6) AppleWebKit/605.1.15 (KHTML, like Gecko) Engine version: 3 Transport: polling Total Clients: 6 Feb 22 16:06:20 main-system volumio-remote-updater[649]: [2025-02-22 16:06:20] [connect] Successful connection Feb 22 16:06:20 main-system volumio-remote-updater[649]: [2025-02-22 16:06:20] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1740258380 101 Feb 22 16:06:20 main-system volumio[861]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 7 Feb 22 16:06:21 main-system volumio[861]: info: CoreCommandRouter::volumioGetState Feb 22 16:06:21 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:21 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 22 16:06:21 main-system volumio[861]: info: CoreCommandRouter::volumioGetVisibleSources Feb 22 16:06:21 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 22 16:06:21 main-system volumio[861]: info: Listing playlists Feb 22 16:06:21 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Feb 22 16:06:21 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 22 16:06:21 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 22 16:06:21 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 22 16:06:21 main-system volumio[861]: info: Initializing connection to go-librespot Websocket Feb 22 16:06:21 main-system go-librespot[1324]: time="2025-02-22T16:06:21-05:00" level=debug msg="new websocket client" Feb 22 16:06:21 main-system volumio[861]: info: Connection to go-librespot Websocket established Feb 22 16:06:23 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 22 16:06:23 main-system volumio[861]: info: Received Get System Info Feb 22 16:06:23 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 22 16:06:23 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 22 16:06:23 main-system volumio[861]: info: Discovery: Getting this device information Feb 22 16:06:23 main-system volumio[861]: info: CoreCommandRouter::volumioGetState Feb 22 16:06:23 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:23 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 22 16:06:24 main-system volumio[861]: info: Getting Spotify volume Feb 22 16:06:24 main-system volumio[861]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Feb 22 16:06:24 main-system volumio[861]: info: CoreCommandRouter::volumioGetState Feb 22 16:06:24 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:24 main-system volumio[861]: SPOTIFY: RECEIVED VOLUMIO VOLUME 98 Feb 22 16:06:24 main-system volumio[861]: SPOTIFY: SPOTIFY VOLUME undefined Feb 22 16:06:24 main-system volumio[861]: SPOTIFY: VOLUMIO VOLUME 98 Feb 22 16:06:24 main-system volumio[861]: info: Aligning Spotify Volume to Volumio Volume Feb 22 16:06:24 main-system volumio[861]: info: CoreCommandRouter::volumioGetState Feb 22 16:06:24 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:24 main-system volumio[861]: info: Setting Spotify Volume from Volumio: 98 Feb 22 16:06:25 main-system volumio[861]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 22 16:06:25 main-system volumio[861]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 22 16:06:25 main-system volumio[861]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 22 16:06:25 main-system volumio[861]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 22 16:06:25 main-system volumio[861]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 22 16:06:25 main-system volumio[861]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 22 16:06:25 main-system volumio[861]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 22 16:06:25 main-system volumio[861]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 22 16:06:25 main-system volumio[861]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 22 16:06:25 main-system volumio[861]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 22 16:06:25 main-system volumio[861]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 22 16:06:25 main-system volumio[861]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 22 16:06:25 main-system volumio[861]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 22 16:06:25 main-system volumio[861]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 22 16:06:25 main-system volumio[861]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 22 16:06:25 main-system volumio[861]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 22 16:06:25 main-system volumio[861]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 22 16:06:25 main-system volumio[861]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 22 16:06:25 main-system volumio[861]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 22 16:06:25 main-system volumio[861]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 22 16:06:25 main-system volumio[861]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 22 16:06:25 main-system volumio[861]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 22 16:06:25 main-system volumio[861]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 22 16:06:25 main-system volumio[861]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 22 16:06:25 main-system volumio[861]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 22 16:06:25 main-system volumio[861]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 22 16:06:25 main-system volumio[861]: info: Adding plugin bluetooth to MyMusic Plugins Feb 22 16:06:25 main-system volumio[861]: info: Adding plugin multiroom to MyMusic Plugins Feb 22 16:06:25 main-system volumio[861]: info: Adding plugin metavolumio to MyMusic Plugins Feb 22 16:06:25 main-system volumio[861]: info: Adding plugin cd_controller to MyMusic Plugins Feb 22 16:06:25 main-system volumio[861]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 22 16:06:25 main-system volumio[861]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 22 16:06:25 main-system volumio[861]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 22 16:06:26 main-system volumio[861]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 22 16:06:26 main-system volumio[861]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 22 16:06:26 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 16:06:26 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 16:06:26 main-system volumio[861]: info: Starting MyVolumio Remote Streaming Endpoints Feb 22 16:06:26 main-system volumio[861]: info: MyVolumio login type: Token Feb 22 16:06:26 main-system volumio[861]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 22 16:06:26 main-system volumio[861]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 22 16:06:27 main-system volumio[861]: info: Starting Streaming Service Transparent Proxy Feb 22 16:06:27 main-system volumio[861]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 22 16:06:27 main-system volumio[861]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 22 16:06:27 main-system volumio[861]: info: Streaming services startup Feb 22 16:06:27 main-system volumio[861]: info: Starting Streaming Daemon Feb 22 16:06:27 main-system sudo[1645]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 22 16:06:27 main-system sudo[1645]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:27 main-system sudo[1645]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:27 main-system volumio[861]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 22 16:06:27 main-system volumio[861]: SPOTIFY: SETTING SPOTIFY VOLUME 98 Feb 22 16:06:27 main-system volumio[861]: info: Sending Spotify command with payload to local API: /player/volume Feb 22 16:06:27 main-system volumio[861]: error: Cannot start Volumio Streaming Daemon Feb 22 16:06:27 main-system volumio[861]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 22 16:06:27 main-system volumio[861]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 22 16:06:27 main-system volumio[861]: error: Failed to send command to Spotify local API: /player/volume: Error: Bad Request Feb 22 16:06:28 main-system volumio[861]: error: MyVolumio Custom Token format not valid, refreshing it Feb 22 16:06:28 main-system volumio[861]: STREAMING PROXY: Starting server on port 3245 Feb 22 16:06:28 main-system volumio[861]: Node JS runtime: 14 Feb 22 16:06:29 main-system volumio[861]: info: MyVolumio login type: Token Feb 22 16:06:29 main-system volumio[861]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 22 16:06:30 main-system volumio[861]: info: MyVolumio token set successfully Feb 22 16:06:30 main-system volumio[861]: info: MYVOLUMIO: Adding device Feb 22 16:06:30 main-system volumio[861]: info: MYVOLUMIO: Evaluating Server Feb 22 16:06:30 main-system volumio[861]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Feb 22 16:06:30 main-system volumio[861]: info: MyVolumio status changed Feb 22 16:06:30 main-system volumio[861]: info: Streaming services startup Feb 22 16:06:30 main-system volumio[861]: info: Starting Streaming Daemon Feb 22 16:06:30 main-system volumio[861]: info: Removing browser output: myVolumio user plan is not superstar Feb 22 16:06:30 main-system volumio[861]: info: Removing audio output: Feb 22 16:06:30 main-system volumio[861]: info: Stoppping Tunnel 1 Feb 22 16:06:30 main-system sudo[1686]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 22 16:06:30 main-system sudo[1686]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:31 main-system sudo[1689]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 22 16:06:31 main-system sudo[1686]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:31 main-system sudo[1689]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 16:06:31 main-system volumio[861]: error: Cannot start Volumio Streaming Daemon Feb 22 16:06:31 main-system volumio[861]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 22 16:06:31 main-system volumio[861]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 22 16:06:31 main-system sudo[1689]: pam_unix(sudo:session): session closed for user root Feb 22 16:06:31 main-system volumio[861]: info: Remote SSH Stopped Feb 22 16:06:31 main-system volumio[861]: info: Setting Geolocation for MyVolumio to us3 Feb 22 16:06:31 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 16:06:31 main-system volumio[861]: info: CoreCommandRouter::volumioGetVisibleSources Feb 22 16:06:31 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 22 16:06:31 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 22 16:06:31 main-system volumio[861]: info: CoreCommandRouter::volumioGetState Feb 22 16:06:31 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:31 main-system volumio[861]: info: CoreCommandRouter::volumioPlay Feb 22 16:06:31 main-system volumio[861]: info: CoreStateMachine::play index undefined Feb 22 16:06:31 main-system volumio[861]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 22 16:06:31 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:31 main-system volumio[861]: info: CoreStateMachine::startPlaybackTimer Feb 22 16:06:31 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:31 main-system volumio[861]: info: [youtube2-play] clearAddPlayTrack: youtube2/video@endpoint:o=%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22Tfkoa8do3l8%22%2C%22params%22%3A%22qgMMSGkgcmVzIG11c2ljugMREg9SRFFNdVJNOThtRWo1WWe6AyQSIlBMTkFWMWlNbnVOT0ZDN3YxSHNWTGVsMTBSQnpqUWxGZWG6AwoI3tTdi5H5uqY8ugMLCNeCuPyAmY-y0AG6AwsIvJvd3cLS8YzYAboDCwj2j-iHmfK5gIgBugMkEiJQTFVWb0g2TzQyWkFiVGpMdFpQQ0poQWh6T250ZzgxYzdOugMKCOPPpd6QsYKNN7oDCgjTlLL_wZbfhla6AwsI2-TqzumeiN2xAboDJBIiUExmTTAwbmNwbE9ROG1UNEMySFdGOG0yTkNianpIUmFER7oDCgiqhKH9yamu-ly6AwoIvNry3YfUqJIFugMkEiJQTDg0elQ1Vzk1RXE4RDRrTEVEMkhBWFc0eEZrU2ZXYzkwugMLCOnAp7i6nLWlpQG6AwoI94bgr6_ykcceugMLCP2w4PbGkJbD9wG6AwsIpfuh37OuvIDWAboDCgjMp7rD9rHwpAvyAwUNTsNhPw%253D%253D%22%7D%7D@explodeTrackData:o=%7B%22title%22%3A%22Absolute%20audiophile%20Hi%20End%20Sound%20test%20Hi%20Res%2032%20bit%20%20HD%20Audio%22%2C%22artist%22%3A%22MAN%20858%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FTfkoa8do3l8%2Fhq720.jpg%3Fsqp%3D-oaymwEcCNAFEJQDSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLAk5yWFl49Gb81szpYbw-iWq_UpgA%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22Tfkoa8do3l8%22%2C%22params%22%3A%22qgMMSGkgcmVzIG11c2ljugMREg9SRFFNdVJNOThtRWo1WWe6AyQSIlBMTkFWMWlNbnVOT0ZDN3YxSHNWTGVsMTBSQnpqUWxGZWG6AwoI3tTdi5H5uqY8ugMLCNeCuPyAmY-y0AG6AwsIvJvd3cLS8YzYAboDCwj2j-iHmfK5gIgBugMkEiJQTFVWb0g2TzQyWkFiVGpMdFpQQ0poQWh6T250ZzgxYzdOugMKCOPPpd6QsYKNN7oDCgjTlLL_wZbfhla6AwsI2-TqzumeiN2xAboDJBIiUExmTTAwbmNwbE9ROG1UNEMySFdGOG0yTkNianpIUmFER7oDCgiqhKH9yamu-ly6AwoIvNry3YfUqJIFugMkEiJQTDg0elQ1Vzk1RXE4RDRrTEVEMkhBWFc0eEZrU2ZXYzkwugMLCOnAp7i6nLWlpQG6AwoI94bgr6_ykcceugMLCP2w4PbGkJbD9wG6AwsIpfuh37OuvIDWAboDCgjMp7rD9rHwpAvyAwUNTsNhPw%253D%253D%22%7D%7D%7D Feb 22 16:06:31 main-system volumio[861]: info: [youtube2] InnertubeLoader: creating Innertube instance... Feb 22 16:06:31 main-system volumio[861]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Feb 22 16:06:31 main-system volumio[861]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 22 16:06:32 main-system volumio[861]: info: Updating MyVolumio device info Feb 22 16:06:32 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 16:06:32 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 16:06:34 main-system systemd[1]: systemd-timedated.service: Succeeded. Feb 22 16:06:38 main-system volumio[861]: info: [youtube2] InnertubeLoader: obtaining po_token by visitorData... Feb 22 16:06:38 main-system volumio[861]: info: AutoStart - Plugin is starting Feb 22 16:06:38 main-system volumio[861]: info: CoreCommandRouter::volumioGetQueue Feb 22 16:06:38 main-system volumio[861]: info: CoreStateMachine::getQueue Feb 22 16:06:38 main-system volumio[861]: info: CorePlayQueue::getQueue Feb 22 16:06:38 main-system volumio[861]: info: AutoStart - start playing Feb 22 16:06:38 main-system volumio[861]: info: AutoStart - start playing with no specific position Feb 22 16:06:38 main-system volumio[861]: info: CoreCommandRouter::volumioPlay Feb 22 16:06:38 main-system volumio[861]: info: CoreStateMachine::play index 0 Feb 22 16:06:38 main-system volumio[861]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 22 16:06:38 main-system volumio[861]: info: CoreStateMachine::stop Feb 22 16:06:38 main-system volumio[861]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 22 16:06:38 main-system volumio[861]: info: CoreStateMachine::play index undefined Feb 22 16:06:38 main-system volumio[861]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 22 16:06:38 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:38 main-system volumio[861]: info: CoreStateMachine::startPlaybackTimer Feb 22 16:06:38 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:38 main-system volumio[861]: info: [youtube2-play] clearAddPlayTrack: youtube2/video@endpoint:o=%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22Tfkoa8do3l8%22%2C%22params%22%3A%22qgMMSGkgcmVzIG11c2ljugMREg9SRFFNdVJNOThtRWo1WWe6AyQSIlBMTkFWMWlNbnVOT0ZDN3YxSHNWTGVsMTBSQnpqUWxGZWG6AwoI3tTdi5H5uqY8ugMLCNeCuPyAmY-y0AG6AwsIvJvd3cLS8YzYAboDCwj2j-iHmfK5gIgBugMkEiJQTFVWb0g2TzQyWkFiVGpMdFpQQ0poQWh6T250ZzgxYzdOugMKCOPPpd6QsYKNN7oDCgjTlLL_wZbfhla6AwsI2-TqzumeiN2xAboDJBIiUExmTTAwbmNwbE9ROG1UNEMySFdGOG0yTkNianpIUmFER7oDCgiqhKH9yamu-ly6AwoIvNry3YfUqJIFugMkEiJQTDg0elQ1Vzk1RXE4RDRrTEVEMkhBWFc0eEZrU2ZXYzkwugMLCOnAp7i6nLWlpQG6AwoI94bgr6_ykcceugMLCP2w4PbGkJbD9wG6AwsIpfuh37OuvIDWAboDCgjMp7rD9rHwpAvyAwUNTsNhPw%253D%253D%22%7D%7D@explodeTrackData:o=%7B%22title%22%3A%22Absolute%20audiophile%20Hi%20End%20Sound%20test%20Hi%20Res%2032%20bit%20%20HD%20Audio%22%2C%22artist%22%3A%22MAN%20858%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FTfkoa8do3l8%2Fhq720.jpg%3Fsqp%3D-oaymwEcCNAFEJQDSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLAk5yWFl49Gb81szpYbw-iWq_UpgA%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22Tfkoa8do3l8%22%2C%22params%22%3A%22qgMMSGkgcmVzIG11c2ljugMREg9SRFFNdVJNOThtRWo1WWe6AyQSIlBMTkFWMWlNbnVOT0ZDN3YxSHNWTGVsMTBSQnpqUWxGZWG6AwoI3tTdi5H5uqY8ugMLCNeCuPyAmY-y0AG6AwsIvJvd3cLS8YzYAboDCwj2j-iHmfK5gIgBugMkEiJQTFVWb0g2TzQyWkFiVGpMdFpQQ0poQWh6T250ZzgxYzdOugMKCOPPpd6QsYKNN7oDCgjTlLL_wZbfhla6AwsI2-TqzumeiN2xAboDJBIiUExmTTAwbmNwbE9ROG1UNEMySFdGOG0yTkNianpIUmFER7oDCgiqhKH9yamu-ly6AwoIvNry3YfUqJIFugMkEiJQTDg0elQ1Vzk1RXE4RDRrTEVEMkhBWFc0eEZrU2ZXYzkwugMLCOnAp7i6nLWlpQG6AwoI94bgr6_ykcceugMLCP2w4PbGkJbD9wG6AwsIpfuh37OuvIDWAboDCgjMp7rD9rHwpAvyAwUNTsNhPw%253D%253D%22%7D%7D%7D Feb 22 16:06:38 main-system volumio[861]: info: MYVOLUMIO: Adding device Feb 22 16:06:38 main-system volumio[861]: info: MYVOLUMIO: Evaluating Server Feb 22 16:06:38 main-system volumio[861]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 22 16:06:38 main-system volumio[861]: info: CoreCommandRouter::volumioGetState Feb 22 16:06:38 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:39 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 22 16:06:39 main-system volumio[861]: info: CoreCommandRouter::volumioGetVisibleSources Feb 22 16:06:39 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 22 16:06:39 main-system volumio[861]: info: Listing playlists Feb 22 16:06:39 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Feb 22 16:06:39 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 22 16:06:39 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 22 16:06:39 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 22 16:06:39 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 22 16:06:39 main-system volumio[861]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Feb 22 16:06:39 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Feb 22 16:06:39 main-system volumio[861]: info: Received Get System Version Feb 22 16:06:39 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 22 16:06:39 main-system volumio[861]: info: Received Get System Info Feb 22 16:06:39 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 22 16:06:39 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 22 16:06:39 main-system volumio[861]: info: Discovery: Getting this device information Feb 22 16:06:39 main-system volumio[861]: info: CoreCommandRouter::volumioGetState Feb 22 16:06:39 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:39 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 22 16:06:40 main-system volumio[861]: info: Setting Geolocation for MyVolumio to us3 Feb 22 16:06:40 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 16:06:40 main-system volumio[861]: info: [youtube2] InnertubeLoader: obtained po_token (expires in 43200 seconds) Feb 22 16:06:40 main-system volumio[861]: info: [youtube2] InnertubeLoader: re-create Innertube instance with po_token Feb 22 16:06:40 main-system volumio[861]: info: [youtube2] InnertubeLoader: creating Innertube instance with po_token... Feb 22 16:06:40 main-system volumio[861]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 22 16:06:45 main-system volumio[861]: info: [youtube2] InnertubeLoader: going to refresh po_token in 43100 seconds Feb 22 16:06:45 main-system volumio[861]: info: Updating MyVolumio device info Feb 22 16:06:45 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 16:06:45 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 22 16:06:45 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 22 16:06:45 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 16:06:45 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 22 16:06:45 main-system volumio[861]: info: CoreCommandRouter::volumioPlay Feb 22 16:06:45 main-system volumio[861]: info: CoreStateMachine::play index undefined Feb 22 16:06:45 main-system volumio[861]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 22 16:06:45 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:45 main-system volumio[861]: info: CoreStateMachine::startPlaybackTimer Feb 22 16:06:45 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:45 main-system volumio[861]: info: [youtube2-play] clearAddPlayTrack: youtube2/video@endpoint:o=%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22Tfkoa8do3l8%22%2C%22params%22%3A%22qgMMSGkgcmVzIG11c2ljugMREg9SRFFNdVJNOThtRWo1WWe6AyQSIlBMTkFWMWlNbnVOT0ZDN3YxSHNWTGVsMTBSQnpqUWxGZWG6AwoI3tTdi5H5uqY8ugMLCNeCuPyAmY-y0AG6AwsIvJvd3cLS8YzYAboDCwj2j-iHmfK5gIgBugMkEiJQTFVWb0g2TzQyWkFiVGpMdFpQQ0poQWh6T250ZzgxYzdOugMKCOPPpd6QsYKNN7oDCgjTlLL_wZbfhla6AwsI2-TqzumeiN2xAboDJBIiUExmTTAwbmNwbE9ROG1UNEMySFdGOG0yTkNianpIUmFER7oDCgiqhKH9yamu-ly6AwoIvNry3YfUqJIFugMkEiJQTDg0elQ1Vzk1RXE4RDRrTEVEMkhBWFc0eEZrU2ZXYzkwugMLCOnAp7i6nLWlpQG6AwoI94bgr6_ykcceugMLCP2w4PbGkJbD9wG6AwsIpfuh37OuvIDWAboDCgjMp7rD9rHwpAvyAwUNTsNhPw%253D%253D%22%7D%7D@explodeTrackData:o=%7B%22title%22%3A%22Absolute%20audiophile%20Hi%20End%20Sound%20test%20Hi%20Res%2032%20bit%20%20HD%20Audio%22%2C%22artist%22%3A%22MAN%20858%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FTfkoa8do3l8%2Fhq720.jpg%3Fsqp%3D-oaymwEcCNAFEJQDSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLAk5yWFl49Gb81szpYbw-iWq_UpgA%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22Tfkoa8do3l8%22%2C%22params%22%3A%22qgMMSGkgcmVzIG11c2ljugMREg9SRFFNdVJNOThtRWo1WWe6AyQSIlBMTkFWMWlNbnVOT0ZDN3YxSHNWTGVsMTBSQnpqUWxGZWG6AwoI3tTdi5H5uqY8ugMLCNeCuPyAmY-y0AG6AwsIvJvd3cLS8YzYAboDCwj2j-iHmfK5gIgBugMkEiJQTFVWb0g2TzQyWkFiVGpMdFpQQ0poQWh6T250ZzgxYzdOugMKCOPPpd6QsYKNN7oDCgjTlLL_wZbfhla6AwsI2-TqzumeiN2xAboDJBIiUExmTTAwbmNwbE9ROG1UNEMySFdGOG0yTkNianpIUmFER7oDCgiqhKH9yamu-ly6AwoIvNry3YfUqJIFugMkEiJQTDg0elQ1Vzk1RXE4RDRrTEVEMkhBWFc0eEZrU2ZXYzkwugMLCOnAp7i6nLWlpQG6AwoI94bgr6_ykcceugMLCP2w4PbGkJbD9wG6AwsIpfuh37OuvIDWAboDCgjMp7rD9rHwpAvyAwUNTsNhPw%253D%253D%22%7D%7D%7D Feb 22 16:06:45 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 22 16:06:45 main-system volumio[861]: info: Received Get System Info Feb 22 16:06:45 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 22 16:06:45 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 22 16:06:45 main-system volumio[861]: info: Discovery: Getting this device information Feb 22 16:06:45 main-system volumio[861]: info: CoreCommandRouter::volumioGetState Feb 22 16:06:45 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:45 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 22 16:06:45 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 22 16:06:45 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 22 16:06:45 main-system volumio[861]: info: Discovery: Getting this device information Feb 22 16:06:45 main-system volumio[861]: info: CoreCommandRouter::volumioGetState Feb 22 16:06:45 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:45 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 22 16:06:45 main-system volumio[861]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Feb 22 16:06:45 main-system volumio-remote-updater[649]: No test mode Feb 22 16:06:45 main-system volumio-remote-updater[649]: No alpha test mode Feb 22 16:06:45 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 22 16:06:45 main-system volumio[861]: info: CoreCommandRouter::volumioGetState Feb 22 16:06:45 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:46 main-system volumio[861]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 22 16:06:46 main-system volumio[861]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Feb 22 16:06:46 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 22 16:06:46 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:46 main-system volumio[861]: verbose: ControllerMpd::sendMpdCommand stop Feb 22 16:06:46 main-system volumio[861]: info: sendMpdCommand stop took 9 milliseconds Feb 22 16:06:46 main-system volumio[861]: verbose: ControllerMpd::sendMpdCommand clear Feb 22 16:06:46 main-system volumio[861]: info: Feb 22 16:06:46 main-system volumio[861]: ---------------------------- MPD announces system playlist update Feb 22 16:06:46 main-system volumio[861]: info: Ignoring MPD Status Update Feb 22 16:06:46 main-system volumio[861]: info: sendMpdCommand clear took 2 milliseconds Feb 22 16:06:46 main-system volumio[861]: verbose: ControllerMpd::sendMpdCommand addid "https://rr4---sn-gvbxgn-tt1ez.googlevideo.com/videoplayback?expire=1740280006&ei=Zjy6Z5rsGvqpir4P5Pu42Qg&ip=99.245.206.199&id=o-AOhzA2nWhhvtgO7VmA-u52GS5e_bcPz6R1YJLILW8a5q&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1740258406%2C&mh=vI&mm=31%2C26&mn=sn-gvbxgn-tt1ez%2Csn-vgqsrnld&ms=au%2Conr&mv=m&mvi=4&pcm2cms=yes&pl=23&rms=au%2Cau&initcwndbps=4616250&bui=AUWDL3xdzskouo-4-3qfFOGMMier4Mz1j5_K4xK5CFq11R_7hZypuwpI8okeCHoz0yla1rZK7awkbj6v&spc=RjZbSR6h5YAS3hzVsc3yLl1HJ49h94rBGwquoidZqQ4jteKzyjyyiKSz_8VAuiM&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=qEUWpsdSaYp8ye-wY1RBvGEQ&rqh=1&gir=yes&clen=116717691&dur=6245.041&lmt=1735359032361375&mt=1740258066&fvip=1&keepalive=yes&fexp=51326932%2C51355912&c=WEB&sefc=1&txp=5432434&n=jfVyr8x8AOQqp0B1eL-_w8_zg65pntqB3oxJ_K&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&sig=AJfQdSswRQIgf49exD9w47ffv3hjyAA-x_W8S2zTFP8R3sWQqXopb2UCIQDEXukk1MfoltONQtMLZWjPlbVYUrOnUloHWNjQwqgVHw%3D%3D&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpcm2cms%2Cpl%2Crms%2Cinitcwndbps&lsig=AGluJ3MwRgIhAMQai2ehFppJMLGff4H6E-p0RByCUZj8lkHQEEYp7A7LAiEA8kStXpCgBPR1K2MCOw4c1hstq9q7_Hkcykg3wllZVME%3D&pot=MngA8XoMiUR8MQDNeLTZVVxRA-yODRNC113McigXjX4sCN8HhMGApOtW1VxcEEpgEYhxAUMMcbdzf33WOIHUX6VpTjVZ7KeStZtN_Je0L50T4N_rCUD1OCi_Lu2V423AG6dWymzXxDPOjblGKbddsCC4-SweDsWDFGE%3D&cver=2.20241121.01.00&t.YouTube" Feb 22 16:06:46 main-system volumio[861]: error: updateQueue error: null Feb 22 16:06:46 main-system volumio[861]: info: Feb 22 16:06:46 main-system volumio[861]: ---------------------------- MPD announces system playlist update Feb 22 16:06:46 main-system volumio[861]: info: Ignoring MPD Status Update Feb 22 16:06:46 main-system volumio[861]: info: ------------------------------ 4ms Feb 22 16:06:46 main-system volumio[861]: info: sendMpdCommand addid "https://rr4---sn-gvbxgn-tt1ez.googlevideo.com/videoplayback?expire=1740280006&ei=Zjy6Z5rsGvqpir4P5Pu42Qg&ip=99.245.206.199&id=o-AOhzA2nWhhvtgO7VmA-u52GS5e_bcPz6R1YJLILW8a5q&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1740258406%2C&mh=vI&mm=31%2C26&mn=sn-gvbxgn-tt1ez%2Csn-vgqsrnld&ms=au%2Conr&mv=m&mvi=4&pcm2cms=yes&pl=23&rms=au%2Cau&initcwndbps=4616250&bui=AUWDL3xdzskouo-4-3qfFOGMMier4Mz1j5_K4xK5CFq11R_7hZypuwpI8okeCHoz0yla1rZK7awkbj6v&spc=RjZbSR6h5YAS3hzVsc3yLl1HJ49h94rBGwquoidZqQ4jteKzyjyyiKSz_8VAuiM&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=qEUWpsdSaYp8ye-wY1RBvGEQ&rqh=1&gir=yes&clen=116717691&dur=6245.041&lmt=1735359032361375&mt=1740258066&fvip=1&keepalive=yes&fexp=51326932%2C51355912&c=WEB&sefc=1&txp=5432434&n=jfVyr8x8AOQqp0B1eL-_w8_zg65pntqB3oxJ_K&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&sig=AJfQdSswRQIgf49exD9w47ffv3hjyAA-x_W8S2zTFP8R3sWQqXopb2UCIQDEXukk1MfoltONQtMLZWjPlbVYUrOnUloHWNjQwqgVHw%3D%3D&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpcm2cms%2Cpl%2Crms%2Cinitcwndbps&lsig=AGluJ3MwRgIhAMQai2ehFppJMLGff4H6E-p0RByCUZj8lkHQEEYp7A7LAiEA8kStXpCgBPR1K2MCOw4c1hstq9q7_Hkcykg3wllZVME%3D&pot=MngA8XoMiUR8MQDNeLTZVVxRA-yODRNC113McigXjX4sCN8HhMGApOtW1VxcEEpgEYhxAUMMcbdzf33WOIHUX6VpTjVZ7KeStZtN_Je0L50T4N_rCUD1OCi_Lu2V423AG6dWymzXxDPOjblGKbddsCC4-SweDsWDFGE%3D&cver=2.20241121.01.00&t.YouTube" took 4 milliseconds Feb 22 16:06:46 main-system volumio[861]: verbose: MPD COMMAND [object Object] Feb 22 16:06:46 main-system volumio[861]: verbose: MPD COMMAND [object Object] Feb 22 16:06:46 main-system volumio[861]: verbose: MPD COMMAND [object Object] Feb 22 16:06:46 main-system volumio[861]: info: Feb 22 16:06:46 main-system volumio[861]: ---------------------------- MPD announces system playlist update Feb 22 16:06:46 main-system volumio[861]: info: Ignoring MPD Status Update Feb 22 16:06:46 main-system volumio[861]: info: ------------------------------ 6ms Feb 22 16:06:46 main-system volumio[861]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 22 16:06:46 main-system volumio[861]: verbose: ControllerMpd::sendMpdCommand play Feb 22 16:06:46 main-system volumio[861]: info: ------------------------------ 2ms Feb 22 16:06:46 main-system volumio[861]: info: sendMpdCommand play took 2 milliseconds Feb 22 16:06:46 main-system volumio[861]: verbose: ControllerMpd::sendMpdCommand stop Feb 22 16:06:46 main-system volumio[861]: info: Feb 22 16:06:46 main-system volumio[861]: ---------------------------- MPD announces state update: player Feb 22 16:06:46 main-system volumio[861]: info: sendMpdCommand stop took 4 milliseconds Feb 22 16:06:46 main-system volumio[861]: info: ControllerMpd::getState Feb 22 16:06:46 main-system volumio[861]: verbose: ControllerMpd::sendMpdCommand status Feb 22 16:06:46 main-system volumio[861]: verbose: ControllerMpd::sendMpdCommand clear Feb 22 16:06:46 main-system volumio[861]: info: Feb 22 16:06:46 main-system volumio[861]: ---------------------------- MPD announces system playlist update Feb 22 16:06:46 main-system volumio[861]: info: Ignoring MPD Status Update Feb 22 16:06:46 main-system volumio[861]: info: sendMpdCommand status took 2 milliseconds Feb 22 16:06:46 main-system volumio[861]: info: sendMpdCommand clear took 2 milliseconds Feb 22 16:06:46 main-system volumio[861]: verbose: ControllerMpd::parseState Feb 22 16:06:46 main-system volumio[861]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 22 16:06:46 main-system volumio[861]: verbose: ControllerMpd::sendMpdCommand addid "https://rr4---sn-gvbxgn-tt1ez.googlevideo.com/videoplayback?expire=1740280006&ei=Zjy6Z6_cHMS1zN0PloGm4Qo&ip=99.245.206.199&id=o-ABSbSPRM1WVcjtHI99BkboAS6P5wBlWETDFRvallI5BK&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1740258406%2C&mh=vI&mm=31%2C26&mn=sn-gvbxgn-tt1ez%2Csn-vgqsrnld&ms=au%2Conr&mv=m&mvi=4&pl=23&rms=au%2Cau&initcwndbps=4616250&bui=AUWDL3zmtbHPnDaxUDRXdcXhTDel1x-9wAQktlb8r9otWy7_erDP_AqXBM1vpKkye_Ed6OiQsHrTzRdO&spc=RjZbSW6PuhooQZHdPZVSLCpoXOvbtD3nC79CwME5zmpB6nXxM5BRZC9rCWmC0Yk&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=OnvhZGSkf180yqMcckVCIMsQ&rqh=1&gir=yes&clen=116717691&dur=6245.041&lmt=1735359032361375&mt=1740258066&fvip=1&keepalive=yes&fexp=51326932%2C51355912&c=WEB&sefc=1&txp=5432434&n=jfVyr8x8AOQqp0B1eL-_w8_4jfKpA-ghhWJv0K&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&sig=AJfQdSswRgIhAKyVEPlUuHxczkUhA4vrYkyrCyqPHCzma1EfV965GfIhAiEAqzOVS9GH-3DNYQxumMtBP-1kK_k9MMDMNAVRX94JnZg%3D&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=AGluJ3MwRQIhAMFhbHyUtolXBGlL9xCryk3YpnL1Eomn1_BntdRLi1ONAiAGjybbT1FpMv17aBw7JchSUl-Cul4yLl_G3hymfh-rrQ%3D%3D&pot=MngA8XoMiUR8MQDNeLTZVVxRA-yODRNC113McigXjX4sCN8HhMGApOtW1VxcEEpgEYhxAUMMcbdzf33WOIHUX6VpTjVZ7KeStZtN_Je0L50T4N_rCUD1OCi_Lu2V423AG6dWymzXxDPOjblGKbddsCC4-SweDsWDFGE%3D&cver=2.20241121.01.00&t.YouTube" Feb 22 16:06:46 main-system volumio[861]: error: updateQueue error: null Feb 22 16:06:46 main-system volumio[861]: info: Feb 22 16:06:46 main-system volumio[861]: ---------------------------- MPD announces system playlist update Feb 22 16:06:46 main-system volumio[861]: info: Ignoring MPD Status Update Feb 22 16:06:46 main-system volumio[861]: info: ------------------------------ 5ms Feb 22 16:06:46 main-system volumio[861]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 22 16:06:46 main-system volumio[861]: info: sendMpdCommand addid "https://rr4---sn-gvbxgn-tt1ez.googlevideo.com/videoplayback?expire=1740280006&ei=Zjy6Z6_cHMS1zN0PloGm4Qo&ip=99.245.206.199&id=o-ABSbSPRM1WVcjtHI99BkboAS6P5wBlWETDFRvallI5BK&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1740258406%2C&mh=vI&mm=31%2C26&mn=sn-gvbxgn-tt1ez%2Csn-vgqsrnld&ms=au%2Conr&mv=m&mvi=4&pl=23&rms=au%2Cau&initcwndbps=4616250&bui=AUWDL3zmtbHPnDaxUDRXdcXhTDel1x-9wAQktlb8r9otWy7_erDP_AqXBM1vpKkye_Ed6OiQsHrTzRdO&spc=RjZbSW6PuhooQZHdPZVSLCpoXOvbtD3nC79CwME5zmpB6nXxM5BRZC9rCWmC0Yk&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=OnvhZGSkf180yqMcckVCIMsQ&rqh=1&gir=yes&clen=116717691&dur=6245.041&lmt=1735359032361375&mt=1740258066&fvip=1&keepalive=yes&fexp=51326932%2C51355912&c=WEB&sefc=1&txp=5432434&n=jfVyr8x8AOQqp0B1eL-_w8_4jfKpA-ghhWJv0K&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&sig=AJfQdSswRgIhAKyVEPlUuHxczkUhA4vrYkyrCyqPHCzma1EfV965GfIhAiEAqzOVS9GH-3DNYQxumMtBP-1kK_k9MMDMNAVRX94JnZg%3D&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=AGluJ3MwRQIhAMFhbHyUtolXBGlL9xCryk3YpnL1Eomn1_BntdRLi1ONAiAGjybbT1FpMv17aBw7JchSUl-Cul4yLl_G3hymfh-rrQ%3D%3D&pot=MngA8XoMiUR8MQDNeLTZVVxRA-yODRNC113McigXjX4sCN8HhMGApOtW1VxcEEpgEYhxAUMMcbdzf33WOIHUX6VpTjVZ7KeStZtN_Je0L50T4N_rCUD1OCi_Lu2V423AG6dWymzXxDPOjblGKbddsCC4-SweDsWDFGE%3D&cver=2.20241121.01.00&t.YouTube" took 2 milliseconds Feb 22 16:06:46 main-system volumio[861]: verbose: ControllerMpd::parseTrackInfo Feb 22 16:06:46 main-system volumio[861]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Feb 22 16:06:46 main-system volumio[861]: verbose: MPD COMMAND [object Object] Feb 22 16:06:46 main-system volumio[861]: verbose: MPD COMMAND [object Object] Feb 22 16:06:46 main-system volumio[861]: verbose: MPD COMMAND [object Object] Feb 22 16:06:46 main-system volumio[861]: info: ------------------------------ 10ms Feb 22 16:06:46 main-system volumio[861]: info: Feb 22 16:06:46 main-system volumio[861]: ---------------------------- MPD announces system playlist update Feb 22 16:06:46 main-system volumio[861]: info: Ignoring MPD Status Update Feb 22 16:06:46 main-system volumio[861]: info: ------------------------------ 6ms Feb 22 16:06:46 main-system volumio[861]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 22 16:06:46 main-system volumio[861]: verbose: ControllerMpd::sendMpdCommand play Feb 22 16:06:46 main-system volumio[861]: info: ------------------------------ 3ms Feb 22 16:06:46 main-system volumio[861]: info: sendMpdCommand play took 2 milliseconds Feb 22 16:06:46 main-system volumio[861]: info: CoreCommandRouter::volumioGetState Feb 22 16:06:46 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:46 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:46 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Feb 22 16:06:46 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Feb 22 16:06:46 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 22 16:06:46 main-system volumio[861]: info: CoreCommandRouter::volumioGetBrowseSources Feb 22 16:06:46 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 22 16:06:46 main-system volumio[861]: verbose: ControllerMpd::sendMpdCommand stop Feb 22 16:06:46 main-system volumio[861]: info: Feb 22 16:06:46 main-system volumio[861]: ---------------------------- MPD announces state update: player Feb 22 16:06:46 main-system volumio[861]: info: sendMpdCommand stop took 25 milliseconds Feb 22 16:06:46 main-system volumio[861]: info: ControllerMpd::getState Feb 22 16:06:46 main-system volumio[861]: verbose: ControllerMpd::sendMpdCommand status Feb 22 16:06:46 main-system volumio[861]: verbose: ControllerMpd::sendMpdCommand clear Feb 22 16:06:46 main-system volumio[861]: info: Feb 22 16:06:46 main-system volumio[861]: ---------------------------- MPD announces system playlist update Feb 22 16:06:46 main-system volumio[861]: info: Ignoring MPD Status Update Feb 22 16:06:46 main-system volumio[861]: info: sendMpdCommand status took 6 milliseconds Feb 22 16:06:46 main-system volumio[861]: info: sendMpdCommand clear took 6 milliseconds Feb 22 16:06:46 main-system volumio[861]: verbose: ControllerMpd::parseState Feb 22 16:06:46 main-system volumio[861]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 22 16:06:46 main-system volumio[861]: verbose: ControllerMpd::sendMpdCommand addid "https://rr4---sn-gvbxgn-tt1ez.googlevideo.com/videoplayback?expire=1740280006&ei=Zjy6Z_bAG8yCut0Pmo3miQM&ip=99.245.206.199&id=o-AD08Ho3U13F0_Ymm3Q1iLODHcwDb7lcuVyWh7xmYYJia&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1740258406%2C&mh=vI&mm=31%2C26&mn=sn-gvbxgn-tt1ez%2Csn-vgqsknzk&ms=au%2Conr&mv=m&mvi=4&pl=23&rms=au%2Cau&initcwndbps=4557500&bui=AUWDL3xx9hy75zk3YGPkeoPUBHinBemlBrB4hvLVQfJzVgTqFwv088eRXcMuswXj2FBRumCk8HdJPyHn&spc=RjZbSdMzoGTH5kPAqBGW1X_OxOMG6_TF59pGH-bpWTWjfbFi7vJF12p82cUnO7w&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=k-NEKoqsI-DR7q86KBIwn5IQ&rqh=1&gir=yes&clen=116717691&dur=6245.041&lmt=1735359032361375&mt=1740257822&fvip=4&keepalive=yes&fexp=51326932%2C51355912&c=WEB&sefc=1&txp=5432434&n=jfVyr8x8AOQqp0B1eL-_w8_ZEWGIw_Z9Hc2fkZ&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&sig=AJfQdSswRQIgA-Uv_3dlObQfpc8lOpENq-IOIHVQ0wP098yayhbd6yECIQChpmTqPvwHAorgCdB9oRLmJlcO2E-whyaBdl1AVqtMow%3D%3D&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=AGluJ3MwRAIgHRoyL2_-pqgWqGYbbEYUZn3iCTnjatj-pYZKPKquDR4CICTh3OFGoANhHgQzCOM_PmDVgV0nTxG3VfGmOyyimN5Z&pot=MngA8XoMiUR8MQDNeLTZVVxRA-yODRNC113McigXjX4sCN8HhMGApOtW1VxcEEpgEYhxAUMMcbdzf33WOIHUX6VpTjVZ7KeStZtN_Je0L50T4N_rCUD1OCi_Lu2V423AG6dWymzXxDPOjblGKbddsCC4-SweDsWDFGE%3D&cver=2.20241121.01.00&t.YouTube" Feb 22 16:06:46 main-system volumio[861]: error: updateQueue error: null Feb 22 16:06:46 main-system volumio[861]: info: Feb 22 16:06:46 main-system volumio[861]: ---------------------------- MPD announces system playlist update Feb 22 16:06:46 main-system volumio[861]: info: Ignoring MPD Status Update Feb 22 16:06:46 main-system volumio[861]: info: ------------------------------ 4ms Feb 22 16:06:46 main-system volumio[861]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 22 16:06:46 main-system volumio[861]: info: sendMpdCommand addid "https://rr4---sn-gvbxgn-tt1ez.googlevideo.com/videoplayback?expire=1740280006&ei=Zjy6Z_bAG8yCut0Pmo3miQM&ip=99.245.206.199&id=o-AD08Ho3U13F0_Ymm3Q1iLODHcwDb7lcuVyWh7xmYYJia&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1740258406%2C&mh=vI&mm=31%2C26&mn=sn-gvbxgn-tt1ez%2Csn-vgqsknzk&ms=au%2Conr&mv=m&mvi=4&pl=23&rms=au%2Cau&initcwndbps=4557500&bui=AUWDL3xx9hy75zk3YGPkeoPUBHinBemlBrB4hvLVQfJzVgTqFwv088eRXcMuswXj2FBRumCk8HdJPyHn&spc=RjZbSdMzoGTH5kPAqBGW1X_OxOMG6_TF59pGH-bpWTWjfbFi7vJF12p82cUnO7w&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=k-NEKoqsI-DR7q86KBIwn5IQ&rqh=1&gir=yes&clen=116717691&dur=6245.041&lmt=1735359032361375&mt=1740257822&fvip=4&keepalive=yes&fexp=51326932%2C51355912&c=WEB&sefc=1&txp=5432434&n=jfVyr8x8AOQqp0B1eL-_w8_ZEWGIw_Z9Hc2fkZ&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&sig=AJfQdSswRQIgA-Uv_3dlObQfpc8lOpENq-IOIHVQ0wP098yayhbd6yECIQChpmTqPvwHAorgCdB9oRLmJlcO2E-whyaBdl1AVqtMow%3D%3D&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=AGluJ3MwRAIgHRoyL2_-pqgWqGYbbEYUZn3iCTnjatj-pYZKPKquDR4CICTh3OFGoANhHgQzCOM_PmDVgV0nTxG3VfGmOyyimN5Z&pot=MngA8XoMiUR8MQDNeLTZVVxRA-yODRNC113McigXjX4sCN8HhMGApOtW1VxcEEpgEYhxAUMMcbdzf33WOIHUX6VpTjVZ7KeStZtN_Je0L50T4N_rCUD1OCi_Lu2V423AG6dWymzXxDPOjblGKbddsCC4-SweDsWDFGE%3D&cver=2.20241121.01.00&t.YouTube" took 2 milliseconds Feb 22 16:06:46 main-system volumio[861]: verbose: ControllerMpd::parseTrackInfo Feb 22 16:06:46 main-system volumio[861]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Feb 22 16:06:46 main-system volumio[861]: verbose: MPD COMMAND [object Object] Feb 22 16:06:46 main-system volumio[861]: verbose: MPD COMMAND [object Object] Feb 22 16:06:46 main-system volumio[861]: verbose: MPD COMMAND [object Object] Feb 22 16:06:46 main-system volumio[861]: info: ------------------------------ 11ms Feb 22 16:06:46 main-system volumio[861]: info: Feb 22 16:06:46 main-system volumio[861]: ---------------------------- MPD announces system playlist update Feb 22 16:06:46 main-system volumio[861]: info: Ignoring MPD Status Update Feb 22 16:06:46 main-system volumio[861]: info: ------------------------------ 4ms Feb 22 16:06:46 main-system volumio[861]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 22 16:06:46 main-system volumio[861]: verbose: ControllerMpd::sendMpdCommand play Feb 22 16:06:46 main-system volumio[861]: info: ------------------------------ 2ms Feb 22 16:06:46 main-system volumio[861]: info: sendMpdCommand play took 2 milliseconds Feb 22 16:06:47 main-system volumio[861]: info: Feb 22 16:06:47 main-system volumio[861]: ---------------------------- MPD announces state update: player Feb 22 16:06:47 main-system volumio[861]: info: ControllerMpd::getState Feb 22 16:06:47 main-system volumio[861]: verbose: ControllerMpd::sendMpdCommand status Feb 22 16:06:47 main-system volumio[861]: verbose: ControllerMpd::sendMpdCommand clearerror Feb 22 16:06:47 main-system volumio[861]: info: sendMpdCommand status took 7 milliseconds Feb 22 16:06:47 main-system volumio[861]: verbose: ControllerMpd::parseState Feb 22 16:06:47 main-system volumio[861]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 22 16:06:47 main-system volumio[861]: info: sendMpdCommand clearerror took 2 milliseconds Feb 22 16:06:47 main-system volumio[861]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 22 16:06:47 main-system volumio[861]: verbose: ControllerMpd::parseTrackInfo Feb 22 16:06:47 main-system volumio[861]: info: ControllerMpd::pushState Feb 22 16:06:47 main-system volumio[861]: info: CoreCommandRouter::servicePushState Feb 22 16:06:47 main-system volumio[861]: info: CoreStateMachine::pushState Feb 22 16:06:47 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:06:47 main-system volumio[861]: info: CoreCommandRouter::volumioPushState Feb 22 16:06:47 main-system volumio[861]: info: CorePlayQueue::getTrack 0 Feb 22 16:06:47 main-system volumio[861]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Absolute audiophile Hi End Sound test Hi Res 32 bit HD Audio","artist":"MAN 858","album":"YouTube","uri":"https://rr4---sn-gvbxgn-tt1ez.googlevideo.com/videoplayback?expire=1740280006&ei=Zjy6Z_bAG8yCut0Pmo3miQM&ip=99.245.206.199&id=o-AD08Ho3U13F0_Ymm3Q1iLODHcwDb7lcuVyWh7xmYYJia&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1740258406%2C&mh=vI&mm=31%2C26&mn=sn-gvbxgn-tt1ez%2Csn-vgqsknzk&ms=au%2Conr&mv=m&mvi=4&pl=23&rms=au%2Cau&initcwndbps=4557500&bui=AUWDL3xx9hy75zk3YGPkeoPUBHinBemlBrB4hvLVQfJzVgTqFwv088eRXcMuswXj2FBRumCk8HdJPyHn&spc=RjZbSdMzoGTH5kPAqBGW1X_OxOMG6_TF59pGH-bpWTWjfbFi7vJF12p82cUnO7w&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=k-NEKoqsI-DR7q86KBIwn5IQ&rqh=1&gir=yes&clen=116717691&dur=6245.041&lmt=1735359032361375&mt=1740257822&fvip=4&keepalive=yes&fexp=51326932%2C51355912&c=WEB&sefc=1&txp=5432434&n=jfVyr8x8AOQqp0B1eL-_w8_ZEWGIw_Z9Hc2fkZ&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&sig=AJfQdSswRQIgA-Uv_3dlObQfpc8lOpENq-IOIHVQ0wP098yayhbd6yECIQChpmTqPvwHAorgCdB9oRLmJlcO2E-whyaBdl1AVqtMow%3D%3D&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=AGluJ3MwRAIgHRoyL2_-pqgWqGYbbEYUZn3iCTnjatj-pYZKPKquDR4CICTh3OFGoANhHgQzCOM_PmDVgV0nTxG3VfGmOyyimN5Z&pot=MngA8XoMiUR8MQDNeLTZVVxRA-yODRNC113McigXjX4sCN8HhMGApOtW1VxcEEpgEYhxAUMMcbdzf33WOIHUX6VpTjVZ7KeStZtN_Je0L50T4N_rCUD1OCi_Lu2V423AG6dWymzXxDPOjblGKbddsCC4-SweDsWDFGE%3D&cver=2.20241121.01.00&t.YouTube","trackType":"YouTube"} Feb 22 16:06:47 main-system volumio[861]: verbose: CURRENT POSITION 0 Feb 22 16:06:47 main-system volumio[861]: info: CoreStateMachine::syncState stateService stop Feb 22 16:06:47 main-system volumio[861]: info: CoreStateMachine::syncState currentStatus stop Feb 22 16:06:47 main-system volumio[861]: info: CoreStateMachine::pushState Feb 22 16:06:47 main-system volumio[861]: info: CoreCommandRouter::volumioPushState Feb 22 16:06:47 main-system volumio[861]: info: No code Feb 22 16:06:47 main-system volumio[861]: info: CoreStateMachine::pushState Feb 22 16:06:47 main-system volumio[861]: info: CoreCommandRouter::volumioPushState Feb 22 16:06:47 main-system volumio[861]: info: ------------------------------ 52ms Feb 22 16:06:47 main-system volumio[861]: SPOTIFY: RECEIVED VOLUMIO VOLUME 98 Feb 22 16:06:47 main-system volumio[861]: SPOTIFY: RECEIVED VOLUMIO VOLUME 98 Feb 22 16:06:47 main-system volumio[861]: SPOTIFY: RECEIVED VOLUMIO VOLUME 98 Feb 22 16:06:47 main-system volumio[861]: error: MyVolumio Plugin failed to authenticate in a timely fashion Feb 22 16:06:47 main-system volumio[861]: info: Completed starting MyVolumio Plugin Feb 22 16:06:47 main-system volumio[861]: [Metrics] CommandRouter: 54s 469.13ms Feb 22 16:06:47 main-system volumio[861]: info: CoreCommandRouter::volumiosetStartupVolume Feb 22 16:06:47 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 16:06:47 main-system volumio[861]: info: VolumeController:: Setting startup Volume 20 Feb 22 16:06:47 main-system volumio[861]: info: VolumeController::SetAlsaVolume20 Feb 22 16:06:47 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 16:06:47 main-system volumio[861]: info: CoreCommandRouter::Close All Modals sent Feb 22 16:06:47 main-system volumio[861]: info: CoreCommandRouter::Close All Modals sent Feb 22 16:06:47 main-system volumio[861]: info: CoreCommandRouter::volumioGetState Feb 22 16:06:47 main-system volumio[861]: info: CoreStateMachine::pushState Feb 22 16:06:47 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 16:06:47 main-system volumio[861]: info: CoreCommandRouter::volumioPushState Feb 22 16:06:47 main-system volumio[861]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Feb 22 16:06:47 main-system volumio[861]: SPOTIFY: SPOTIFY VOLUME 98 Feb 22 16:06:47 main-system volumio[861]: SPOTIFY: VOLUMIO VOLUME 20 Feb 22 16:06:47 main-system volumio[861]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 22 16:06:47 main-system volumio[861]: info: Setting Spotify Volume from Volumio: 20 Feb 22 16:06:48 main-system volumiologrotate[610]: ls: cannot access '/var/log/samba/log.wb-MAIN': No such file or directory Feb 22 16:06:48 main-system volumiologrotate[610]: ls: cannot access 'SYSTEM': No such file or directory Feb 22 16:06:48 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Feb 22 16:06:48 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 22 16:06:48 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Feb 22 16:06:49 main-system volumio[861]: SPOTIFY: SETTING SPOTIFY VOLUME 20 Feb 22 16:06:49 main-system volumio[861]: info: Sending Spotify command with payload to local API: /player/volume Feb 22 16:06:50 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 22 16:06:50 main-system volumio[861]: info: Preload queue cleared Feb 22 16:06:50 main-system volumio[861]: info: CoreCommandRouter::volumioGetQueue Feb 22 16:06:50 main-system volumio[861]: info: CoreStateMachine::getQueue Feb 22 16:06:50 main-system volumio[861]: info: CorePlayQueue::getQueue Feb 22 16:06:50 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 22 16:06:50 main-system volumio[861]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Feb 22 16:06:50 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Feb 22 16:06:50 main-system volumio[861]: info: Received Get System Version Feb 22 16:06:50 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 22 16:06:50 main-system volumio[861]: info: Received Get System Info Feb 22 16:06:50 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 22 16:06:50 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 22 16:06:50 main-system volumio[861]: info: Discovery: Getting this device information Feb 22 16:06:50 main-system volumio[861]: info: CoreCommandRouter::volumioGetState Feb 22 16:06:50 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 22 16:06:52 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 22 16:06:52 main-system volumio[861]: info: Preload queue cleared Feb 22 16:06:53 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 22 16:06:53 main-system volumio[861]: info: Preload queue cleared Feb 22 16:06:54 main-system volumio[861]: info: BOOT COMPLETED Feb 22 16:06:55 main-system ntpd[828]: Soliciting pool server 54.39.196.172 Feb 22 16:06:57 main-system ntpd[828]: Soliciting pool server 216.6.2.70 Feb 22 16:06:57 main-system volumio[861]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 22 16:06:57 main-system volumio[861]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 22 16:06:57 main-system volumio[861]: TypeError: Cannot read property 'length' of undefined Feb 22 16:06:57 main-system volumio[861]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Feb 22 16:06:57 main-system volumio[861]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Feb 22 16:06:57 main-system volumio[861]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Feb 22 16:06:57 main-system volumio[861]: at Parser.emit (events.js:315:20) Feb 22 16:06:57 main-system volumio[861]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Feb 22 16:06:57 main-system volumio[861]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Feb 22 16:06:57 main-system volumio[861]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Feb 22 16:06:57 main-system volumio[861]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Feb 22 16:06:57 main-system volumio[861]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Feb 22 16:06:57 main-system volumio[861]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Feb 22 16:06:57 main-system volumio[861]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Feb 22 16:06:57 main-system volumio[861]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Feb 22 16:06:57 main-system volumio[861]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Feb 22 16:06:57 main-system volumio[861]: at IncomingMessage.emit (events.js:327:22) Feb 22 16:06:57 main-system volumio[861]: at endReadableNT (internal/streams/readable.js:1327:12) Feb 22 16:06:57 main-system volumio[861]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Feb 22 16:06:57 main-system volumio[861]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 22 16:06:58 main-system sudo[2015]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-02-22 16:05 Feb 22 16:06:58 main-system sudo[2015]: 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="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"