-- Logs begin at Thu 2019-02-14 02:11:59 PST, end at Sun 2024-09-08 09:03:55 PDT. -- Sep 08 09:02:00 minidsp-shd volumio[839]: info: Plugin multiroom is not enabled Sep 08 09:02:00 minidsp-shd volumio[839]: info: Loading plugin "outputs"... Sep 08 09:02:00 minidsp-shd volumio[839]: info: Loading plugin "albumart"... Sep 08 09:02:00 minidsp-shd volumio[839]: info: Loading plugin "ms_surface_dial"... Sep 08 09:02:01 minidsp-shd volumio[839]: Forking 3 albumart workers Sep 08 09:02:01 minidsp-shd volumio[839]: info: Applying required configuration parameters for plugin ms_surface_dial Sep 08 09:02:01 minidsp-shd volumio[839]: info: Plugin example_plugin is not enabled Sep 08 09:02:01 minidsp-shd volumio[839]: info: Loading plugin "hi_res_audio"... Sep 08 09:02:02 minidsp-shd volumio[839]: Starting albumart workers Sep 08 09:02:02 minidsp-shd volumio[839]: Starting albumart workers Sep 08 09:02:02 minidsp-shd volumio[839]: Starting albumart workers Sep 08 09:02:03 minidsp-shd volumio[839]: info: Applying required configuration parameters for plugin hi_res_audio Sep 08 09:02:03 minidsp-shd volumio[839]: info: Loading plugin "inputs"... Sep 08 09:02:04 minidsp-shd volumio[839]: info: Loading plugin "qobuz"... Sep 08 09:02:05 minidsp-shd volumio[839]: info: Loading plugin "tidal"... Sep 08 09:02:07 minidsp-shd volumio[839]: info: Loading plugin "oem_helper"... Sep 08 09:02:08 minidsp-shd volumio[839]: info: Applying required configuration parameters for plugin oem_helper Sep 08 09:02:08 minidsp-shd volumio[839]: info: Loading plugin "updater_comm"... Sep 08 09:02:08 minidsp-shd volumio[839]: info: Plugin mpdemulation is not enabled Sep 08 09:02:08 minidsp-shd volumio[839]: info: Loading plugin "rest_api"... Sep 08 09:02:08 minidsp-shd volumio[839]: info: Loading plugin "websocket"... Sep 08 09:02:08 minidsp-shd volumio[839]: info: Loading plugin "motherearthradio"... Sep 08 09:02:09 minidsp-shd volumio[839]: info: Applying required configuration parameters for plugin motherearthradio Sep 08 09:02:09 minidsp-shd volumio[839]: info: [1725811329311] [MotherEarth] API delay: 5 Sep 08 09:02:09 minidsp-shd volumio[839]: info: Loading i18n strings for locale en Sep 08 09:02:09 minidsp-shd volumio[839]: Updating browse sources language Sep 08 09:02:09 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 08 09:02:09 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 08 09:02:09 minidsp-shd volumio[839]: info: CoreCommandRouter::initPlayerControls Sep 08 09:02:09 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:09 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:09 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:09 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:09 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:09 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:09 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:09 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:09 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 08 09:02:09 minidsp-shd volumio[839]: Express server listening on port 3000 Sep 08 09:02:09 minidsp-shd volumio[839]: [Metrics] WebUI: 24s 872.22ms Sep 08 09:02:09 minidsp-shd volumio[839]: info: CoreStateMachine::resetVolumioState Sep 08 09:02:09 minidsp-shd volumio[839]: info: CoreStateMachine::getcurrentVolume Sep 08 09:02:09 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioRetrievevolume Sep 08 09:02:09 minidsp-shd volumio[839]: info: CoreStateMachine::pushState Sep 08 09:02:09 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:02:09 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 08 09:02:09 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioPushState Sep 08 09:02:09 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 08 09:02:09 minidsp-shd sudo[991]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 08 09:02:09 minidsp-shd sudo[991]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:02:09 minidsp-shd sudo[991]: pam_unix(sudo:session): session closed for user root Sep 08 09:02:09 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: inputs , getVolume Sep 08 09:02:09 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: inputs , getDSP Sep 08 09:02:09 minidsp-shd sudo[995]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 08 09:02:09 minidsp-shd sudo[995]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:02:09 minidsp-shd volumio[839]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Sep 08 09:02:09 minidsp-shd volumio[839]: info: Completed loading Core Plugins Sep 08 09:02:09 minidsp-shd volumio[839]: info: Preparing to generate the ALSA configuration file Sep 08 09:02:09 minidsp-shd sudo[995]: pam_unix(sudo:session): session closed for user root Sep 08 09:02:09 minidsp-shd volumio[839]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Sep 08 09:02:09 minidsp-shd volumio[839]: wlan0 Interface doesn't support scanning. Sep 08 09:02:09 minidsp-shd volumio[839]: info: Cannot use regular scanning, forcing with ap-force Sep 08 09:02:10 minidsp-shd sudo[1000]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Sep 08 09:02:10 minidsp-shd sudo[1000]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:02:10 minidsp-shd sudo[1000]: pam_unix(sudo:session): session closed for user root Sep 08 09:02:10 minidsp-shd volumio[839]: command failed: No such device (-19) Sep 08 09:02:10 minidsp-shd volumio[839]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Sep 08 09:02:10 minidsp-shd volumio[839]: command failed: No such device (-19) Sep 08 09:02:10 minidsp-shd volumio[839]: verbose: New Socket.io Connection to 192.168.68.54 from 192.168.68.65 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.6 Mobile/15E148 Safari/604.1 Total Clients: 1 Sep 08 09:02:10 minidsp-shd volumio[839]: verbose: New Socket.io Connection to 192.168.68.54 from 192.168.68.65 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.6 Mobile/15E148 Safari/604.1 Total Clients: 2 Sep 08 09:02:10 minidsp-shd volumio[839]: verbose: New Socket.io Connection to 192.168.68.54 from 192.168.68.65 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.6 Mobile/15E148 Safari/604.1 Total Clients: 3 Sep 08 09:02:10 minidsp-shd volumio[839]: info: Asound.conf file unchanged, so no further update is needed Sep 08 09:02:10 minidsp-shd volumio[839]: info: Output device has changed, restarting MPD Sep 08 09:02:10 minidsp-shd sudo[1015]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 08 09:02:10 minidsp-shd sudo[1015]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:02:10 minidsp-shd sudo[1015]: pam_unix(sudo:session): session closed for user root Sep 08 09:02:10 minidsp-shd volumio[839]: info: Output device has changed, restarting Shairport Sync Sep 08 09:02:10 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:10 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 08 09:02:10 minidsp-shd sudo[1018]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 08 09:02:10 minidsp-shd sudo[1018]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:02:10 minidsp-shd systemd[1]: Stopping Music Player Daemon... Sep 08 09:02:10 minidsp-shd volumio[839]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 08 09:02:10 minidsp-shd volumio[839]: info: ___________ START PLUGINS ___________ Sep 08 09:02:10 minidsp-shd volumio[839]: info: ControllerMpd::onStart: Initializing MPD Sep 08 09:02:10 minidsp-shd volumio[839]: info: Creating MPD Configuration file Sep 08 09:02:10 minidsp-shd sudo[1024]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 08 09:02:10 minidsp-shd sudo[1024]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:02:10 minidsp-shd sudo[1024]: pam_unix(sudo:session): session closed for user root Sep 08 09:02:10 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 08 09:02:10 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 08 09:02:10 minidsp-shd volumio[839]: info: [1725811330697] CoreMusicLibrary::Adding element Media Servers Sep 08 09:02:10 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 08 09:02:10 minidsp-shd sudo[1028]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 08 09:02:10 minidsp-shd sudo[1028]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:02:10 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 08 09:02:10 minidsp-shd volumio[839]: info: Adding Manifest REST API Endpoints Sep 08 09:02:10 minidsp-shd volumio[839]: info: Adding manifestui REST Endpoint for plugin: miscellanea/manifestui Sep 08 09:02:10 minidsp-shd volumio[839]: info: Adding METAVOLUMIO REST API Endpoints Sep 08 09:02:10 minidsp-shd volumio[839]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Sep 08 09:02:10 minidsp-shd volumio[839]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Sep 08 09:02:10 minidsp-shd volumio[839]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Sep 08 09:02:10 minidsp-shd volumio[839]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Sep 08 09:02:10 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:10 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 08 09:02:10 minidsp-shd sudo[1033]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name miniDSP SHD Sep 08 09:02:10 minidsp-shd sudo[1033]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:02:10 minidsp-shd sudo[1033]: pam_unix(sudo:session): session closed for user root Sep 08 09:02:10 minidsp-shd volumio[839]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 08 09:02:10 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:10 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 08 09:02:10 minidsp-shd systemd[1]: mpd.service: Succeeded. Sep 08 09:02:10 minidsp-shd systemd[1]: Stopped Music Player Daemon. Sep 08 09:02:10 minidsp-shd systemd[1]: Starting Music Player Daemon... Sep 08 09:02:10 minidsp-shd volumio[839]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 08 09:02:10 minidsp-shd volumio[839]: info: Preparing CD Folders Sep 08 09:02:10 minidsp-shd volumio[839]: info: Adding CD REST API Endpoints Sep 08 09:02:10 minidsp-shd volumio[839]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Sep 08 09:02:10 minidsp-shd volumio[839]: info: Starting UDEV Watcher for CD Sep 08 09:02:10 minidsp-shd volumio[839]: info: Detecting CD presence with UDEV Sep 08 09:02:10 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Sep 08 09:02:11 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 08 09:02:11 minidsp-shd volumio[839]: info: [1725811331013] CoreMusicLibrary::Adding element Last_100 Sep 08 09:02:11 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 08 09:02:11 minidsp-shd volumio[839]: info: Starting RAAT Plugin Sep 08 09:02:11 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections Sep 08 09:02:11 minidsp-shd volumio[839]: info: Additional UI Settings Added for plugin music_service/raat Sep 08 09:02:11 minidsp-shd volumio[839]: info: Streaming services startup Sep 08 09:02:11 minidsp-shd volumio[839]: info: Starting Streaming Daemon Sep 08 09:02:11 minidsp-shd sudo[1045]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Sep 08 09:02:11 minidsp-shd sudo[1045]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:02:11 minidsp-shd sudo[1045]: pam_unix(sudo:session): session closed for user root Sep 08 09:02:11 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 08 09:02:11 minidsp-shd volumio[839]: info: [1725811331213] CoreMusicLibrary::Adding element Webradio Sep 08 09:02:11 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 08 09:02:11 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 08 09:02:11 minidsp-shd sudo[1054]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Sep 08 09:02:11 minidsp-shd sudo[1054]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:02:11 minidsp-shd volumio[839]: info: Adding Calm Radio to Browse Sources Sep 08 09:02:11 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 08 09:02:11 minidsp-shd volumio[839]: info: [1725811331241] CoreMusicLibrary::Adding element Calm Radio Sep 08 09:02:11 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 08 09:02:11 minidsp-shd volumio[839]: Cannot find translation for source Calm Radio Sep 08 09:02:11 minidsp-shd systemd[1]: Stopping Volumio Tidal Connect Service... Sep 08 09:02:11 minidsp-shd systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM Sep 08 09:02:11 minidsp-shd systemd[1]: vtcs.service: Succeeded. Sep 08 09:02:11 minidsp-shd systemd[1]: Stopped Volumio Tidal Connect Service. Sep 08 09:02:11 minidsp-shd volumio[839]: info: Creating Spotify config file Sep 08 09:02:11 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:11 minidsp-shd sudo[1054]: pam_unix(sudo:session): session closed for user root Sep 08 09:02:11 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 08 09:02:11 minidsp-shd volumio[839]: info: [1725811331431] CoreMusicLibrary::Adding element YouTube2 Sep 08 09:02:11 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 08 09:02:11 minidsp-shd volumio[839]: Cannot find translation for source Calm Radio Sep 08 09:02:11 minidsp-shd volumio[839]: Cannot find translation for source YouTube2 Sep 08 09:02:11 minidsp-shd volumio[839]: error: Hi Res Audio Failed Login: Missing Login Data Sep 08 09:02:11 minidsp-shd volumio[839]: info: Adding HIGHRESAUDIO REST API Endpoints Sep 08 09:02:11 minidsp-shd volumio[839]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Sep 08 09:02:11 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 08 09:02:11 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 08 09:02:11 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 08 09:02:11 minidsp-shd volumio[839]: info: [1725811331608] CoreMusicLibrary::Adding element Mother Earth Radio Sep 08 09:02:11 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 08 09:02:11 minidsp-shd volumio[839]: Cannot find translation for source Calm Radio Sep 08 09:02:11 minidsp-shd volumio[839]: Cannot find translation for source YouTube2 Sep 08 09:02:11 minidsp-shd volumio[839]: Cannot find translation for source Mother Earth Radio Sep 08 09:02:11 minidsp-shd volumio[839]: info: Volumio Calling Home Sep 08 09:02:11 minidsp-shd volumio[839]: info: Stopping AccessToken refresher cron for QOBUZ Sep 08 09:02:11 minidsp-shd volumio[839]: info: AccessToken refresher cron started for QOBUZ Sep 08 09:02:11 minidsp-shd volumio[839]: info: Stopping AccessToken refresher cron Sep 08 09:02:11 minidsp-shd volumio[839]: info: AccessToken refresher cron started Sep 08 09:02:11 minidsp-shd volumio[839]: info: Adding TIDAL REST API Endpoints Sep 08 09:02:11 minidsp-shd volumio[839]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Sep 08 09:02:11 minidsp-shd volumio[839]: info: Adding QOBUZ REST API Endpoints Sep 08 09:02:11 minidsp-shd volumio[839]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreStateMachine::setRepeat false single undefined Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreStateMachine::pushState Sep 08 09:02:12 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioPushState Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreStateMachine::setRandom true Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreStateMachine::pushState Sep 08 09:02:12 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioPushState Sep 08 09:02:12 minidsp-shd volumio[839]: info: Setting Device type: NanoPi NEO 2 Sep 08 09:02:12 minidsp-shd volumio[839]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo ENOTFOUND oauth-performer.dfs.volumio.org Sep 08 09:02:12 minidsp-shd volumio[839]: info: Serial port opened successfully Sep 08 09:02:12 minidsp-shd volumio[839]: error: Cannot start Volumio Streaming Daemon Sep 08 09:02:12 minidsp-shd volumio[839]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Sep 08 09:02:12 minidsp-shd volumio[839]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Sep 08 09:02:12 minidsp-shd volumio[839]: error: Cannot set new Bluetooth Name : Error: Command failed: /usr/bin/sudo /bin/hciconfig hci0 name 'miniDSP SHD' Sep 08 09:02:12 minidsp-shd volumio[839]: Can't get device info: No such device Sep 08 09:02:12 minidsp-shd volumio[839]: info: MPD Permissions set Sep 08 09:02:12 minidsp-shd volumio[839]: info: MPD Permissions set Sep 08 09:02:12 minidsp-shd volumio[839]: info: msSurfaceDial Managed Objs {"/org/bluez":{"org.freedesktop.DBus.Introspectable":{},"org.bluez.AgentManager1":{},"org.bluez.ProfileManager1":{}}} Sep 08 09:02:12 minidsp-shd volumio[839]: info: [msSurfaceDial init()] check /org/bluez Sep 08 09:02:12 minidsp-shd volumio[839]: info: [msSurfaceDial init()] Adapter: null; SurfaceDial: null Sep 08 09:02:12 minidsp-shd sudo[1080]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Sep 08 09:02:12 minidsp-shd volumio[839]: info: msSurfaceDial BluetoothSurfaceDial init() - ready! Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::Reload Ui Sep 08 09:02:12 minidsp-shd sudo[1080]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:02:12 minidsp-shd volumio[839]: info: Spotify config file written Sep 08 09:02:12 minidsp-shd sudo[1080]: pam_unix(sudo:session): session closed for user root Sep 08 09:02:12 minidsp-shd sudo[1084]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Sep 08 09:02:12 minidsp-shd sudo[1084]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:02:12 minidsp-shd volumio[839]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 4 Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:12 minidsp-shd systemd[1]: Stopping go-librespot Daemon... Sep 08 09:02:12 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Sep 08 09:02:12 minidsp-shd systemd[1]: go-librespot-daemon.service: Succeeded. Sep 08 09:02:12 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 09:02:12 minidsp-shd ntpd[30790]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Sep 08 09:02:12 minidsp-shd ntpd[30790]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Sep 08 09:02:12 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Sep 08 09:02:12 minidsp-shd sudo[1084]: pam_unix(sudo:session): session closed for user root Sep 08 09:02:12 minidsp-shd go-librespot[1090]: Librespot-go daemon starting... Sep 08 09:02:12 minidsp-shd go-librespot[1090]: time="2024-09-08T09:02:12-07:00" level=info msg="generated new device id: 7f9824f34e14663793f009b4256283972146ccd3" Sep 08 09:02:12 minidsp-shd go-librespot[1090]: time="2024-09-08T09:02:12-07:00" level=debug msg="stored credentials found for seyf1gokh2xqje3i089bqxgpz" Sep 08 09:02:12 minidsp-shd go-librespot[1090]: time="2024-09-08T09:02:12-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Sep 08 09:02:12 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 09:02:12 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:12 minidsp-shd volumio[839]: info: Discovery: adding 923ec171-67ad-4b26-8a71-f4f034e27242 Sep 08 09:02:12 minidsp-shd volumio[839]: info: Discovery: Found device miniDSP SHD Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetState Sep 08 09:02:12 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:02:12 minidsp-shd volumio[839]: info: msSurfaceDial volumioupdatevolume callback: {"vol":57,"dbVolume":-55,"disableVolumeControl":false} Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreStateMachine::pushState Sep 08 09:02:12 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioPushState Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Sep 08 09:02:12 minidsp-shd volumio[839]: info: Ignoring ROON Volume update because of undefined data Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: raat , updateDSP Sep 08 09:02:12 minidsp-shd volumio[839]: info: updateDSP function in raat called! Sep 08 09:02:12 minidsp-shd volumio[839]: info: Updating RAAT Signal Path Sep 08 09:02:12 minidsp-shd volumio[839]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: raat , reconfigureAndRestartRaat Sep 08 09:02:12 minidsp-shd volumio[839]: info: Reconfiguring and Restarting RAAT Plugin Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 08 09:02:12 minidsp-shd volumio[839]: info: Not Reporting Auto name since its the default one Sep 08 09:02:12 minidsp-shd volumio[839]: info: RAAT Overriding default device vendor model Sep 08 09:02:12 minidsp-shd volumio[839]: info: Adding MINIDSP Inputs Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 08 09:02:12 minidsp-shd volumio[839]: info: [1725811332733] CoreMusicLibrary::Adding element Inputs Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 08 09:02:12 minidsp-shd volumio[839]: Cannot find translation for source Calm Radio Sep 08 09:02:12 minidsp-shd volumio[839]: Cannot find translation for source YouTube2 Sep 08 09:02:12 minidsp-shd volumio[839]: Cannot find translation for source Mother Earth Radio Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 08 09:02:12 minidsp-shd volumio[839]: info: [1725811332740] CoreMusicLibrary::Adding element Presets Sep 08 09:02:12 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 08 09:02:12 minidsp-shd volumio[839]: Cannot find translation for source Calm Radio Sep 08 09:02:12 minidsp-shd volumio[839]: Cannot find translation for source YouTube2 Sep 08 09:02:12 minidsp-shd volumio[839]: Cannot find translation for source Mother Earth Radio Sep 08 09:02:12 minidsp-shd volumio[839]: Cannot find translation for source Presets Sep 08 09:02:12 minidsp-shd volumio[839]: (node:839) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead. Sep 08 09:02:12 minidsp-shd volumio[839]: (Use `node --trace-deprecation ...` to show where the warning was created) Sep 08 09:02:12 minidsp-shd volumio[839]: info: Upmpdcli Daemon Started Sep 08 09:02:12 minidsp-shd volumio[839]: info: Starting Shairport Sync Sep 08 09:02:12 minidsp-shd volumio[839]: info: Starting Shairport Sync Sep 08 09:02:12 minidsp-shd sudo[1117]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 08 09:02:12 minidsp-shd sudo[1117]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:02:12 minidsp-shd volumio[839]: info: Starting Shairport Sync Sep 08 09:02:12 minidsp-shd sudo[1120]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 08 09:02:12 minidsp-shd sudo[1120]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:02:12 minidsp-shd shairport-sync[1027]: {"time":1725811233987,"response":"startAirplayPlayback Success"} Sep 08 09:02:12 minidsp-shd systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 08 09:02:12 minidsp-shd systemd[1]: shairport-sync.service: Succeeded. Sep 08 09:02:12 minidsp-shd systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 08 09:02:13 minidsp-shd systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 08 09:02:13 minidsp-shd sudo[1117]: pam_unix(sudo:session): session closed for user root Sep 08 09:02:13 minidsp-shd sudo[1123]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 08 09:02:13 minidsp-shd sudo[1123]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:02:13 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Sep 08 09:02:13 minidsp-shd systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 08 09:02:13 minidsp-shd systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Sep 08 09:02:13 minidsp-shd systemd[1]: shairport-sync.service: Succeeded. Sep 08 09:02:13 minidsp-shd systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 08 09:02:13 minidsp-shd systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 08 09:02:13 minidsp-shd sudo[1120]: pam_unix(sudo:session): session closed for user root Sep 08 09:02:13 minidsp-shd sudo[1123]: pam_unix(sudo:session): session closed for user root Sep 08 09:02:13 minidsp-shd sudo[1133]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Sep 08 09:02:13 minidsp-shd sudo[1133]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:02:13 minidsp-shd systemd[1]: Stopping RAAT DAEMON... Sep 08 09:02:13 minidsp-shd systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Sep 08 09:02:13 minidsp-shd systemd[1]: raat-daemon.service: Succeeded. Sep 08 09:02:13 minidsp-shd systemd[1]: Stopped RAAT DAEMON. Sep 08 09:02:13 minidsp-shd systemd[1]: Started RAAT DAEMON. Sep 08 09:02:13 minidsp-shd sudo[1133]: pam_unix(sudo:session): session closed for user root Sep 08 09:02:13 minidsp-shd volumio[839]: info: Shairport-Sync Started Sep 08 09:02:13 minidsp-shd volumio[839]: Error adding Membership: Error: addMembership EINVAL Sep 08 09:02:13 minidsp-shd volumio[839]: info: Raat Daemon started successfully Sep 08 09:02:13 minidsp-shd volumio[839]: info: Shairport-Sync Started Sep 08 09:02:13 minidsp-shd volumio[839]: info: Shairport-Sync Started Sep 08 09:02:13 minidsp-shd sudo[1148]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 08 09:02:13 minidsp-shd sudo[1148]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:02:13 minidsp-shd sudo[1148]: pam_unix(sudo:session): session closed for user root Sep 08 09:02:13 minidsp-shd sudo[1151]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 08 09:02:13 minidsp-shd sudo[1151]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:02:13 minidsp-shd volumio[839]: info: CoreCommandRouter::volumiosetSourceActiveno-source Sep 08 09:02:13 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 08 09:02:13 minidsp-shd volumio[839]: Cannot find translation for source Calm Radio Sep 08 09:02:13 minidsp-shd volumio[839]: Cannot find translation for source YouTube2 Sep 08 09:02:13 minidsp-shd volumio[839]: Cannot find translation for source Mother Earth Radio Sep 08 09:02:13 minidsp-shd volumio[839]: Cannot find translation for source Presets Sep 08 09:02:13 minidsp-shd sudo[1151]: pam_unix(sudo:session): session closed for user root Sep 08 09:02:13 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetState Sep 08 09:02:13 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:02:13 minidsp-shd mpd[1040]: Sep 08 09:02 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 08 09:02:13 minidsp-shd systemd[1]: Started Music Player Daemon. Sep 08 09:02:13 minidsp-shd sudo[1018]: pam_unix(sudo:session): session closed for user root Sep 08 09:02:13 minidsp-shd sudo[1028]: pam_unix(sudo:session): session closed for user root Sep 08 09:02:13 minidsp-shd volumio[839]: info: Executing endpoint restartRAATSocket Sep 08 09:02:13 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Sep 08 09:02:13 minidsp-shd sudo[1161]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Sep 08 09:02:13 minidsp-shd sudo[1161]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:02:13 minidsp-shd volumio[839]: info: MPD running with PID1040 Sep 08 09:02:13 minidsp-shd volumio[839]: ,establishing connection Sep 08 09:02:13 minidsp-shd sudo[1161]: pam_unix(sudo:session): session closed for user root Sep 08 09:02:13 minidsp-shd volumio[839]: error: MPD error: The expression evaluated to a falsy value: Sep 08 09:02:13 minidsp-shd volumio[839]: assert.ok(self.idling) Sep 08 09:02:13 minidsp-shd volumio[839]: error: The expression evaluated to a falsy value: Sep 08 09:02:13 minidsp-shd volumio[839]: assert.ok(self.idling) Sep 08 09:02:13 minidsp-shd volumio[839]: error: MPD error: The expression evaluated to a falsy value: Sep 08 09:02:13 minidsp-shd volumio[839]: assert.ok(self.idling) Sep 08 09:02:13 minidsp-shd volumio[839]: error: The expression evaluated to a falsy value: Sep 08 09:02:13 minidsp-shd volumio[839]: assert.ok(self.idling) Sep 08 09:02:14 minidsp-shd volumio[839]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 5 Sep 08 09:02:14 minidsp-shd volumio[839]: verbose: New Socket.io Connection to 192.168.68.54 from 192.168.68.65 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.6 Mobile/15E148 Safari/604.1 Total Clients: 6 Sep 08 09:02:14 minidsp-shd volumio[839]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Sep 08 09:02:14 minidsp-shd volumio[839]: info: Volumio BT Module successfully started Sep 08 09:02:14 minidsp-shd volumio[839]: error: updateQueue error: null Sep 08 09:02:14 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Sep 08 09:02:14 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 08 09:02:14 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetVisibleSources Sep 08 09:02:14 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 08 09:02:14 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetState Sep 08 09:02:14 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:02:14 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Sep 08 09:02:14 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 08 09:02:14 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: inputs , handleBrowseUri Sep 08 09:02:14 minidsp-shd volumio[839]: info: Received Get System Info Sep 08 09:02:14 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 08 09:02:14 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 08 09:02:14 minidsp-shd volumio[839]: info: Discovery: Getting this device information Sep 08 09:02:14 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetState Sep 08 09:02:14 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:02:14 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 08 09:02:14 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetState Sep 08 09:02:14 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:02:14 minidsp-shd volumio[839]: info: Listing playlists Sep 08 09:02:14 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Sep 08 09:02:14 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 08 09:02:14 minidsp-shd volumio[839]: info: TidalConnect service stoped! Sep 08 09:02:14 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Sep 08 09:02:14 minidsp-shd volumio[839]: info: Enabling external Volume Control Sep 08 09:02:14 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:14 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:14 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetState Sep 08 09:02:14 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:02:14 minidsp-shd volumio[839]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Sep 08 09:02:14 minidsp-shd volumio[839]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Sep 08 09:02:14 minidsp-shd sudo[1172]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Sep 08 09:02:14 minidsp-shd sudo[1172]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:02:14 minidsp-shd systemd[1]: Started Volumio Tidal Connect Service. Sep 08 09:02:14 minidsp-shd sudo[1172]: pam_unix(sudo:session): session closed for user root Sep 08 09:02:14 minidsp-shd volumio-remote-updater[455]: [2024-09-08 09:02:14] [connect] Successful connection Sep 08 09:02:14 minidsp-shd volumio-remote-updater[455]: [2024-09-08 09:02:14] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1725811334 101 Sep 08 09:02:14 minidsp-shd volumio[839]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 8 Sep 08 09:02:14 minidsp-shd volumio[839]: info: Executing endpoint tc_getconfig Sep 08 09:02:14 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Sep 08 09:02:14 minidsp-shd vtcs[1174]: STARTING TidalConnect services, version: 1.3.0.19 Sep 08 09:02:15 minidsp-shd vtcs[1174]: STARTED TidalConnect services. Sep 08 09:02:15 minidsp-shd volumio[839]: info: Executing endpoint tc_connect Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Sep 08 09:02:15 minidsp-shd volumio[839]: info: Connecting to TidalConnect Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 08 09:02:15 minidsp-shd volumio[839]: info: Received Get System Info Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 08 09:02:15 minidsp-shd volumio[839]: info: Discovery: Getting this device information Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetState Sep 08 09:02:15 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreCommandRouter::servicePushState Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreStateMachine::pushState Sep 08 09:02:15 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioPushState Sep 08 09:02:15 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:02:15 minidsp-shd volumio[839]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Sep 08 09:02:15 minidsp-shd volumio[839]: verbose: CURRENT POSITION 0 Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreStateMachine::syncState stateService stop Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreStateMachine::syncState currentStatus stop Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreStateMachine::pushState Sep 08 09:02:15 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioPushState Sep 08 09:02:15 minidsp-shd volumio[839]: info: No code Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreStateMachine::pushState Sep 08 09:02:15 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioPushState Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreCommandRouter::servicePushState Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreStateMachine::pushState Sep 08 09:02:15 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioPushState Sep 08 09:02:15 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:02:15 minidsp-shd volumio[839]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Sep 08 09:02:15 minidsp-shd volumio[839]: verbose: CURRENT POSITION 0 Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreStateMachine::syncState stateService stop Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreStateMachine::syncState currentStatus stop Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreStateMachine::pushState Sep 08 09:02:15 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioPushState Sep 08 09:02:15 minidsp-shd volumio[839]: info: No code Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreStateMachine::pushState Sep 08 09:02:15 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioPushState Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 08 09:02:15 minidsp-shd volumio[839]: info: Received Get System Info Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 08 09:02:15 minidsp-shd volumio[839]: info: Discovery: Getting this device information Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetState Sep 08 09:02:15 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 08 09:02:15 minidsp-shd volumio[839]: info: msSurfaceDial volumioupdatevolume callback: {"vol":57,"dbVolume":-55,"mute":false,"disableVolumeControl":false} Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreStateMachine::pushState Sep 08 09:02:15 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioPushState Sep 08 09:02:15 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 09:02:15 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Sep 08 09:02:15 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 09:02:15 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 09:02:15 minidsp-shd go-librespot[1192]: Librespot-go daemon starting... Sep 08 09:02:15 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Sep 08 09:02:15 minidsp-shd go-librespot[1192]: time="2024-09-08T09:02:15-07:00" level=info msg="generated new device id: 6b93365bfa12669088000689e9d717ac4439742b" Sep 08 09:02:15 minidsp-shd go-librespot[1192]: time="2024-09-08T09:02:15-07:00" level=debug msg="stored credentials found for seyf1gokh2xqje3i089bqxgpz" Sep 08 09:02:15 minidsp-shd go-librespot[1192]: time="2024-09-08T09:02:15-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Sep 08 09:02:15 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 09:02:15 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 09:02:15 minidsp-shd volumio[839]: info: go-librespot daemon successfully initialized Sep 08 09:02:16 minidsp-shd volumio[839]: info: msSurfaceDial volumioupdatevolume callback: {"vol":57,"dbVolume":-55,"mute":false,"disableVolumeControl":false} Sep 08 09:02:16 minidsp-shd volumio[839]: info: CoreStateMachine::pushState Sep 08 09:02:16 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:02:16 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioPushState Sep 08 09:02:16 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Sep 08 09:02:17 minidsp-shd volumio[839]: info: TidalConnect service started! Sep 08 09:02:17 minidsp-shd volumio[839]: info: Completed starting Core Plugins Sep 08 09:02:17 minidsp-shd volumio[839]: info: ------------------------------------------- Sep 08 09:02:17 minidsp-shd volumio[839]: info: ----- MyVolumio plugins startup ---- Sep 08 09:02:17 minidsp-shd volumio[839]: info: ------------------------------------------- Sep 08 09:02:17 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Fetching plans data.... Sep 08 09:02:18 minidsp-shd volumio[839]: info: Initializing connection to go-librespot Websocket Sep 08 09:02:18 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 09:02:18 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Sep 08 09:02:18 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 09:02:18 minidsp-shd volumio[839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 09:02:18 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 09:02:18 minidsp-shd go-librespot[1200]: Librespot-go daemon starting... Sep 08 09:02:18 minidsp-shd go-librespot[1200]: time="2024-09-08T09:02:18-07:00" level=info msg="generated new device id: c0b316c3956684a150395c298b01285425260c34" Sep 08 09:02:18 minidsp-shd go-librespot[1200]: time="2024-09-08T09:02:18-07:00" level=debug msg="stored credentials found for seyf1gokh2xqje3i089bqxgpz" Sep 08 09:02:18 minidsp-shd volumio[839]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Sep 08 09:02:18 minidsp-shd go-librespot[1200]: time="2024-09-08T09:02:18-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Sep 08 09:02:18 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 09:02:18 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 09:02:20 minidsp-shd volumio[839]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 08 09:02:20 minidsp-shd volumio[839]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 08 09:02:20 minidsp-shd volumio[839]: info: Retrieving Cloud Streaming UI Sep 08 09:02:20 minidsp-shd volumio[839]: info: Getting Tidal Cloud Configuration Sep 08 09:02:20 minidsp-shd volumio[839]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 08 09:02:20 minidsp-shd volumio[839]: info: Getting Qobuz Cloud Configuration Sep 08 09:02:20 minidsp-shd volumio[839]: info: Asking plugin for UI Config Sep 08 09:02:20 minidsp-shd volumio[839]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 08 09:02:20 minidsp-shd volumio[839]: info: Getting Spotify Cloud Configuration Sep 08 09:02:20 minidsp-shd volumio[839]: info: Asking plugin for UI Config Sep 08 09:02:20 minidsp-shd volumio[839]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 08 09:02:20 minidsp-shd volumio[839]: info: Saving Spotify Acccount Sep 08 09:02:20 minidsp-shd volumio[839]: info: Got it Sep 08 09:02:20 minidsp-shd volumio[839]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Sep 08 09:02:20 minidsp-shd volumio[839]: info: Got Tidal Cloud Configuration Sep 08 09:02:20 minidsp-shd volumio[839]: info: Got it Sep 08 09:02:20 minidsp-shd volumio[839]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 08 09:02:20 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Sep 08 09:02:20 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Sep 08 09:02:20 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Sep 08 09:02:20 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Sep 08 09:02:20 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 08 09:02:20 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 08 09:02:20 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 08 09:02:20 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 08 09:02:20 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetBrowseSources Sep 08 09:02:20 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetBrowseSources Sep 08 09:02:20 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetBrowseSources Sep 08 09:02:21 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:21 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:21 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:21 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:21 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 08 09:02:21 minidsp-shd volumio[839]: info: Not Reporting Auto name since its the default one Sep 08 09:02:21 minidsp-shd volumio[839]: info: RAAT Overriding default device vendor model Sep 08 09:02:21 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Sep 08 09:02:21 minidsp-shd volumio[839]: xcb_connection_has_error() returned true Sep 08 09:02:21 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 08 09:02:21 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Sep 08 09:02:21 minidsp-shd sudo[1215]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Sep 08 09:02:21 minidsp-shd sudo[1215]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:02:21 minidsp-shd systemd[1]: Stopping RAAT DAEMON... Sep 08 09:02:21 minidsp-shd systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Sep 08 09:02:21 minidsp-shd systemd[1]: raat-daemon.service: Succeeded. Sep 08 09:02:21 minidsp-shd systemd[1]: Stopped RAAT DAEMON. Sep 08 09:02:21 minidsp-shd systemd[1]: Started RAAT DAEMON. Sep 08 09:02:21 minidsp-shd volumio[839]: ------------------------------------ BT MESSAGE: BT STATUS: running Sep 08 09:02:21 minidsp-shd volumio[839]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Sep 08 09:02:21 minidsp-shd sudo[1215]: pam_unix(sudo:session): session closed for user root Sep 08 09:02:21 minidsp-shd volumio[839]: info: Raat Daemon started successfully Sep 08 09:02:21 minidsp-shd volumio[839]: info: Executing endpoint restartRAATSocket Sep 08 09:02:21 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Sep 08 09:02:21 minidsp-shd volumio[839]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Sep 08 09:02:21 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: raat , updateDSP Sep 08 09:02:21 minidsp-shd volumio[839]: info: updateDSP function in raat called! Sep 08 09:02:21 minidsp-shd volumio[839]: info: Updating RAAT Signal Path Sep 08 09:02:21 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetState Sep 08 09:02:21 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:02:21 minidsp-shd volumio[839]: info: Initializing connection to go-librespot Websocket Sep 08 09:02:21 minidsp-shd volumio[839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 09:02:22 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 09:02:22 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Sep 08 09:02:22 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 09:02:22 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 09:02:22 minidsp-shd go-librespot[1230]: Librespot-go daemon starting... Sep 08 09:02:22 minidsp-shd go-librespot[1230]: time="2024-09-08T09:02:22-07:00" level=info msg="generated new device id: 6e24cc807e3d3ed600ce56f0c01310b8207a3eef" Sep 08 09:02:22 minidsp-shd go-librespot[1230]: time="2024-09-08T09:02:22-07:00" level=debug msg="stored credentials found for seyf1gokh2xqje3i089bqxgpz" Sep 08 09:02:22 minidsp-shd go-librespot[1230]: time="2024-09-08T09:02:22-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Sep 08 09:02:22 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 09:02:22 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 09:02:22 minidsp-shd volumio[839]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=nanopineo2&variante=minidspshd&version=3.608&uuid=bdc70414ffe56897e375558fd3aa091c" http://updates.volumio.org/downloader-v1/track-device Sep 08 09:02:22 minidsp-shd volumio[839]: % Total % Received % Xferd Average Speed Time Time Time Current Sep 08 09:02:22 minidsp-shd volumio[839]: Dload Upload Total Spent Left Speed Sep 08 09:02:22 minidsp-shd volumio[839]: [132B blob data] Sep 08 09:02:22 minidsp-shd volumio[839]: retrying in 5 seconds, trial 0 Sep 08 09:02:22 minidsp-shd volumio[839]: info: Volumio Calling Home Sep 08 09:02:23 minidsp-shd ntpd[30790]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Sep 08 09:02:24 minidsp-shd volumio[839]: info: Initializing connection to go-librespot Websocket Sep 08 09:02:24 minidsp-shd volumio[839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 09:02:25 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Sep 08 09:02:25 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 09:02:25 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Sep 08 09:02:25 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 09:02:25 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 09:02:25 minidsp-shd go-librespot[1240]: Librespot-go daemon starting... Sep 08 09:02:25 minidsp-shd go-librespot[1240]: time="2024-09-08T09:02:25-07:00" level=info msg="generated new device id: 3aa0e6cf86f470bc7666621df06fb886256e44a1" Sep 08 09:02:25 minidsp-shd go-librespot[1240]: time="2024-09-08T09:02:25-07:00" level=debug msg="stored credentials found for seyf1gokh2xqje3i089bqxgpz" Sep 08 09:02:25 minidsp-shd go-librespot[1240]: time="2024-09-08T09:02:25-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Sep 08 09:02:25 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 09:02:25 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 09:02:27 minidsp-shd volumio[839]: info: Initializing connection to go-librespot Websocket Sep 08 09:02:27 minidsp-shd volumio[839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 09:02:28 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 09:02:28 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Sep 08 09:02:28 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 09:02:28 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 09:02:28 minidsp-shd go-librespot[1248]: Librespot-go daemon starting... Sep 08 09:02:28 minidsp-shd go-librespot[1248]: time="2024-09-08T09:02:28-07:00" level=info msg="generated new device id: 64a7bf6e042cf4e0848eee464cb29adbb8046b12" Sep 08 09:02:28 minidsp-shd go-librespot[1248]: time="2024-09-08T09:02:28-07:00" level=debug msg="stored credentials found for seyf1gokh2xqje3i089bqxgpz" Sep 08 09:02:28 minidsp-shd go-librespot[1248]: time="2024-09-08T09:02:28-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Sep 08 09:02:28 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 09:02:28 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 09:02:28 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetQueue Sep 08 09:02:28 minidsp-shd volumio[839]: info: CoreStateMachine::getQueue Sep 08 09:02:28 minidsp-shd volumio[839]: info: CorePlayQueue::getQueue Sep 08 09:02:30 minidsp-shd volumio[839]: info: Initializing connection to go-librespot Websocket Sep 08 09:02:30 minidsp-shd volumio[839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 09:02:31 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 08 09:02:31 minidsp-shd volumio[839]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Sep 08 09:02:31 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Sep 08 09:02:31 minidsp-shd volumio[839]: info: Received Get System Version Sep 08 09:02:31 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 08 09:02:31 minidsp-shd volumio[839]: info: Received Get System Info Sep 08 09:02:31 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 08 09:02:31 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 08 09:02:31 minidsp-shd volumio[839]: info: Discovery: Getting this device information Sep 08 09:02:31 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetState Sep 08 09:02:31 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:02:31 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 08 09:02:31 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 09:02:31 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Sep 08 09:02:31 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 09:02:31 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 09:02:31 minidsp-shd go-librespot[1256]: Librespot-go daemon starting... Sep 08 09:02:31 minidsp-shd go-librespot[1256]: time="2024-09-08T09:02:31-07:00" level=info msg="generated new device id: 8574969fbed92f13c9a3b712eeb5a9740266c0e1" Sep 08 09:02:31 minidsp-shd go-librespot[1256]: time="2024-09-08T09:02:31-07:00" level=debug msg="stored credentials found for seyf1gokh2xqje3i089bqxgpz" Sep 08 09:02:31 minidsp-shd go-librespot[1256]: time="2024-09-08T09:02:31-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Sep 08 09:02:31 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 09:02:31 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 09:02:32 minidsp-shd volumio[839]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=nanopineo2&variante=minidspshd&version=3.608&uuid=bdc70414ffe56897e375558fd3aa091c" http://updates.volumio.org/downloader-v1/track-device Sep 08 09:02:32 minidsp-shd volumio[839]: % Total % Received % Xferd Average Speed Time Time Time Current Sep 08 09:02:32 minidsp-shd volumio[839]: Dload Upload Total Spent Left Speed Sep 08 09:02:32 minidsp-shd volumio[839]: [132B blob data] Sep 08 09:02:32 minidsp-shd volumio[839]: retrying in 5 seconds, trial 1 Sep 08 09:02:32 minidsp-shd volumio[839]: info: Volumio Calling Home Sep 08 09:02:32 minidsp-shd ntpd[30790]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Sep 08 09:02:33 minidsp-shd volumio[839]: info: Initializing connection to go-librespot Websocket Sep 08 09:02:33 minidsp-shd volumio[839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 09:02:35 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 09:02:35 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Sep 08 09:02:35 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 09:02:35 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 09:02:35 minidsp-shd go-librespot[1266]: Librespot-go daemon starting... Sep 08 09:02:35 minidsp-shd go-librespot[1266]: time="2024-09-08T09:02:35-07:00" level=info msg="generated new device id: 807ba39deb1d19b1be8d2474e4bab7dcd5677849" Sep 08 09:02:35 minidsp-shd go-librespot[1266]: time="2024-09-08T09:02:35-07:00" level=debug msg="stored credentials found for seyf1gokh2xqje3i089bqxgpz" Sep 08 09:02:35 minidsp-shd go-librespot[1266]: time="2024-09-08T09:02:35-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Sep 08 09:02:35 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 09:02:35 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 09:02:36 minidsp-shd volumio[839]: info: Initializing connection to go-librespot Websocket Sep 08 09:02:36 minidsp-shd volumio[839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 09:02:37 minidsp-shd volumio[839]: error: MyVolumio Plugin failed to start in a timely fashion Sep 08 09:02:37 minidsp-shd volumio[839]: info: BOOT COMPLETED Sep 08 09:02:37 minidsp-shd volumio[839]: [Metrics] CommandRouter: 51s 899.08ms Sep 08 09:02:37 minidsp-shd volumio[839]: info: CoreCommandRouter::volumiosetStartupVolume Sep 08 09:02:37 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:02:37 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 08 09:02:37 minidsp-shd volumio[839]: info: CoreCommandRouter::Close All Modals sent Sep 08 09:02:37 minidsp-shd volumio[839]: info: CoreCommandRouter::Close All Modals sent Sep 08 09:02:38 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 09:02:38 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Sep 08 09:02:38 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 09:02:38 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 09:02:38 minidsp-shd go-librespot[1276]: Librespot-go daemon starting... Sep 08 09:02:38 minidsp-shd go-librespot[1276]: time="2024-09-08T09:02:38-07:00" level=info msg="generated new device id: 42b1069697baec2f64b9a9e3300bb582deea75ee" Sep 08 09:02:38 minidsp-shd go-librespot[1276]: time="2024-09-08T09:02:38-07:00" level=debug msg="stored credentials found for seyf1gokh2xqje3i089bqxgpz" Sep 08 09:02:38 minidsp-shd go-librespot[1276]: time="2024-09-08T09:02:38-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Sep 08 09:02:38 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 09:02:38 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 09:02:38 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Sep 08 09:02:38 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 08 09:02:38 minidsp-shd volumio[839]: xcb_connection_has_error() returned true Sep 08 09:02:38 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Sep 08 09:02:39 minidsp-shd volumio[839]: info: Initializing connection to go-librespot Websocket Sep 08 09:02:39 minidsp-shd volumio[839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 09:02:41 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 09:02:41 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Sep 08 09:02:41 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 09:02:41 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 09:02:41 minidsp-shd go-librespot[1286]: Librespot-go daemon starting... Sep 08 09:02:41 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 08 09:02:41 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 08 09:02:41 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 08 09:02:41 minidsp-shd go-librespot[1286]: time="2024-09-08T09:02:41-07:00" level=info msg="generated new device id: 4c4ac84cdb5b8a052fc27a19f97cc630cbb55a1a" Sep 08 09:02:41 minidsp-shd go-librespot[1286]: time="2024-09-08T09:02:41-07:00" level=debug msg="stored credentials found for seyf1gokh2xqje3i089bqxgpz" Sep 08 09:02:41 minidsp-shd go-librespot[1286]: time="2024-09-08T09:02:41-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Sep 08 09:02:41 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 09:02:41 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 09:02:42 minidsp-shd volumio[839]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=nanopineo2&variante=minidspshd&version=3.608&uuid=bdc70414ffe56897e375558fd3aa091c" http://updates.volumio.org/downloader-v1/track-device Sep 08 09:02:42 minidsp-shd volumio[839]: % Total % Received % Xferd Average Speed Time Time Time Current Sep 08 09:02:42 minidsp-shd volumio[839]: Dload Upload Total Spent Left Speed Sep 08 09:02:42 minidsp-shd volumio[839]: [132B blob data] Sep 08 09:02:42 minidsp-shd volumio[839]: retrying in 5 seconds, trial 2 Sep 08 09:02:42 minidsp-shd volumio[839]: info: Volumio Calling Home Sep 08 09:02:42 minidsp-shd volumio[839]: info: Initializing connection to go-librespot Websocket Sep 08 09:02:42 minidsp-shd volumio[839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 09:02:44 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 09:02:44 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Sep 08 09:02:44 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 09:02:44 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 09:02:44 minidsp-shd go-librespot[1298]: Librespot-go daemon starting... Sep 08 09:02:44 minidsp-shd go-librespot[1298]: time="2024-09-08T09:02:44-07:00" level=info msg="generated new device id: 19a003d0c283ce6fbb482ab21adf9617e09df8b1" Sep 08 09:02:44 minidsp-shd go-librespot[1298]: time="2024-09-08T09:02:44-07:00" level=debug msg="stored credentials found for seyf1gokh2xqje3i089bqxgpz" Sep 08 09:02:44 minidsp-shd go-librespot[1298]: time="2024-09-08T09:02:44-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Sep 08 09:02:44 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 09:02:44 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 09:02:45 minidsp-shd volumio[839]: info: Initializing connection to go-librespot Websocket Sep 08 09:02:45 minidsp-shd volumio[839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 09:02:48 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 09:02:48 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Sep 08 09:02:48 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 09:02:48 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 09:02:48 minidsp-shd go-librespot[1305]: Librespot-go daemon starting... Sep 08 09:02:48 minidsp-shd go-librespot[1305]: time="2024-09-08T09:02:48-07:00" level=info msg="generated new device id: 3de4819c9449b45ae181720b7dba859bd08d580e" Sep 08 09:02:48 minidsp-shd go-librespot[1305]: time="2024-09-08T09:02:48-07:00" level=debug msg="stored credentials found for seyf1gokh2xqje3i089bqxgpz" Sep 08 09:02:48 minidsp-shd go-librespot[1305]: time="2024-09-08T09:02:48-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Sep 08 09:02:48 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 09:02:48 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 09:02:48 minidsp-shd volumio[839]: info: Initializing connection to go-librespot Websocket Sep 08 09:02:48 minidsp-shd volumio[839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 09:02:51 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 09:02:51 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Sep 08 09:02:51 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 09:02:51 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 09:02:51 minidsp-shd go-librespot[1312]: Librespot-go daemon starting... Sep 08 09:02:51 minidsp-shd go-librespot[1312]: time="2024-09-08T09:02:51-07:00" level=info msg="generated new device id: 27d223c40e63b133aa01721de88da1ebbf2a1cf2" Sep 08 09:02:51 minidsp-shd go-librespot[1312]: time="2024-09-08T09:02:51-07:00" level=debug msg="stored credentials found for seyf1gokh2xqje3i089bqxgpz" Sep 08 09:02:51 minidsp-shd go-librespot[1312]: time="2024-09-08T09:02:51-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Sep 08 09:02:51 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 09:02:51 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 09:02:51 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Sep 08 09:02:51 minidsp-shd volumio[839]: info: CURURI: music-library Sep 08 09:02:51 minidsp-shd volumio[839]: error: Failed LSINFO: null Sep 08 09:02:51 minidsp-shd volumio[839]: info: Preload queue cleared Sep 08 09:02:51 minidsp-shd volumio[839]: info: Initializing connection to go-librespot Websocket Sep 08 09:02:51 minidsp-shd volumio[839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 09:02:54 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 09:02:54 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Sep 08 09:02:54 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 09:02:54 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 09:02:54 minidsp-shd go-librespot[1321]: Librespot-go daemon starting... Sep 08 09:02:54 minidsp-shd go-librespot[1321]: time="2024-09-08T09:02:54-07:00" level=info msg="generated new device id: c90aeed31f2da84bf8ecd9f250638b1c5b7c9261" Sep 08 09:02:54 minidsp-shd go-librespot[1321]: time="2024-09-08T09:02:54-07:00" level=debug msg="stored credentials found for seyf1gokh2xqje3i089bqxgpz" Sep 08 09:02:54 minidsp-shd go-librespot[1321]: time="2024-09-08T09:02:54-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Sep 08 09:02:54 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 09:02:54 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 09:02:54 minidsp-shd volumio[839]: info: Initializing connection to go-librespot Websocket Sep 08 09:02:54 minidsp-shd volumio[839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 09:02:57 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 09:02:57 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Sep 08 09:02:57 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 09:02:57 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 09:02:57 minidsp-shd go-librespot[1329]: Librespot-go daemon starting... Sep 08 09:02:57 minidsp-shd go-librespot[1329]: time="2024-09-08T09:02:57-07:00" level=info msg="generated new device id: 9090dd0253eaf524dc091e06e6a521b9f084bbee" Sep 08 09:02:57 minidsp-shd go-librespot[1329]: time="2024-09-08T09:02:57-07:00" level=debug msg="stored credentials found for seyf1gokh2xqje3i089bqxgpz" Sep 08 09:02:57 minidsp-shd go-librespot[1329]: time="2024-09-08T09:02:57-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Sep 08 09:02:57 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 09:02:57 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 09:02:57 minidsp-shd volumio[839]: info: Initializing connection to go-librespot Websocket Sep 08 09:02:57 minidsp-shd volumio[839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 09:03:00 minidsp-shd volumio[839]: info: Initializing connection to go-librespot Websocket Sep 08 09:03:00 minidsp-shd volumio[839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 09:03:01 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 09:03:01 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Sep 08 09:03:01 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 09:03:01 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 09:03:01 minidsp-shd go-librespot[1336]: Librespot-go daemon starting... Sep 08 09:03:01 minidsp-shd go-librespot[1336]: time="2024-09-08T09:03:01-07:00" level=info msg="generated new device id: 11d504982fddaeea9584d1dc80d7babcda0ddae8" Sep 08 09:03:01 minidsp-shd go-librespot[1336]: time="2024-09-08T09:03:01-07:00" level=debug msg="stored credentials found for seyf1gokh2xqje3i089bqxgpz" Sep 08 09:03:01 minidsp-shd go-librespot[1336]: time="2024-09-08T09:03:01-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Sep 08 09:03:01 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 09:03:01 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 09:03:03 minidsp-shd sudo[1345]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 08 09:03:03 minidsp-shd sudo[1345]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:03:03 minidsp-shd sudo[1345]: pam_unix(sudo:session): session closed for user root Sep 08 09:03:03 minidsp-shd sudo[1348]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 08 09:03:03 minidsp-shd sudo[1348]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:03:03 minidsp-shd sudo[1348]: pam_unix(sudo:session): session closed for user root Sep 08 09:03:03 minidsp-shd volumio[839]: verbose: New Socket.io Connection to 192.168.68.54 from 192.168.68.65 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.6 Mobile/15E148 Safari/604.1 Total Clients: 9 Sep 08 09:03:03 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: inputs , handleBrowseUri Sep 08 09:03:03 minidsp-shd volumio[839]: info: Received Get System Info Sep 08 09:03:03 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 08 09:03:03 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 08 09:03:03 minidsp-shd volumio[839]: info: Discovery: Getting this device information Sep 08 09:03:03 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetState Sep 08 09:03:03 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:03:03 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 08 09:03:03 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetState Sep 08 09:03:03 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:03:03 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Sep 08 09:03:03 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 08 09:03:03 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetVisibleSources Sep 08 09:03:03 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 08 09:03:03 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetState Sep 08 09:03:03 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:03:03 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Sep 08 09:03:03 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 08 09:03:03 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: inputs , handleBrowseUri Sep 08 09:03:03 minidsp-shd volumio[839]: info: Received Get System Info Sep 08 09:03:03 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 08 09:03:03 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 08 09:03:03 minidsp-shd volumio[839]: info: Discovery: Getting this device information Sep 08 09:03:03 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetState Sep 08 09:03:03 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:03:03 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 08 09:03:03 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetState Sep 08 09:03:03 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:03:03 minidsp-shd volumio[839]: info: Listing playlists Sep 08 09:03:04 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetQueue Sep 08 09:03:04 minidsp-shd volumio[839]: info: CoreStateMachine::getQueue Sep 08 09:03:04 minidsp-shd volumio[839]: info: CorePlayQueue::getQueue Sep 08 09:03:04 minidsp-shd volumio[839]: info: Initializing connection to go-librespot Websocket Sep 08 09:03:04 minidsp-shd volumio[839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 09:03:04 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 09:03:04 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Sep 08 09:03:04 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 09:03:04 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 09:03:04 minidsp-shd go-librespot[1352]: Librespot-go daemon starting... Sep 08 09:03:04 minidsp-shd go-librespot[1352]: time="2024-09-08T09:03:04-07:00" level=info msg="generated new device id: f0f892db4ef5dd685261e1568b35253b549eadc8" Sep 08 09:03:04 minidsp-shd go-librespot[1352]: time="2024-09-08T09:03:04-07:00" level=debug msg="stored credentials found for seyf1gokh2xqje3i089bqxgpz" Sep 08 09:03:04 minidsp-shd go-librespot[1352]: time="2024-09-08T09:03:04-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Sep 08 09:03:04 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 09:03:04 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 09:03:05 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 08 09:03:05 minidsp-shd volumio[839]: info: Received Get System Info Sep 08 09:03:05 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 08 09:03:05 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 08 09:03:05 minidsp-shd volumio[839]: info: Discovery: Getting this device information Sep 08 09:03:05 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetState Sep 08 09:03:05 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:03:05 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 08 09:03:06 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Sep 08 09:03:06 minidsp-shd sudo[1398]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 08 09:03:06 minidsp-shd sudo[1398]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:03:06 minidsp-shd sudo[1398]: pam_unix(sudo:session): session closed for user root Sep 08 09:03:07 minidsp-shd sudo[1401]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 08 09:03:07 minidsp-shd sudo[1401]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:03:07 minidsp-shd sudo[1401]: pam_unix(sudo:session): session closed for user root Sep 08 09:03:07 minidsp-shd volumio[839]: info: Initializing connection to go-librespot Websocket Sep 08 09:03:07 minidsp-shd volumio[839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 09:03:07 minidsp-shd volumio[839]: verbose: New Socket.io Connection to 192.168.68.54 from 192.168.68.65 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.6 Mobile/15E148 Safari/604.1 Total Clients: 9 Sep 08 09:03:07 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: inputs , handleBrowseUri Sep 08 09:03:07 minidsp-shd volumio[839]: info: Received Get System Info Sep 08 09:03:07 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 08 09:03:07 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 08 09:03:07 minidsp-shd volumio[839]: info: Discovery: Getting this device information Sep 08 09:03:07 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetState Sep 08 09:03:07 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:03:07 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 08 09:03:07 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetState Sep 08 09:03:07 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:03:07 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Sep 08 09:03:07 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 08 09:03:07 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetVisibleSources Sep 08 09:03:07 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 08 09:03:07 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetState Sep 08 09:03:07 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:03:07 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Sep 08 09:03:07 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 08 09:03:07 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: inputs , handleBrowseUri Sep 08 09:03:07 minidsp-shd volumio[839]: info: Received Get System Info Sep 08 09:03:07 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 08 09:03:07 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 08 09:03:07 minidsp-shd volumio[839]: info: Discovery: Getting this device information Sep 08 09:03:07 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetState Sep 08 09:03:07 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:03:07 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 08 09:03:07 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetState Sep 08 09:03:07 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:03:07 minidsp-shd volumio[839]: info: Listing playlists Sep 08 09:03:07 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetQueue Sep 08 09:03:07 minidsp-shd volumio[839]: info: CoreStateMachine::getQueue Sep 08 09:03:07 minidsp-shd volumio[839]: info: CorePlayQueue::getQueue Sep 08 09:03:07 minidsp-shd volumio[839]: info: Received Get System Info Sep 08 09:03:07 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 08 09:03:07 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 08 09:03:07 minidsp-shd volumio[839]: info: Discovery: Getting this device information Sep 08 09:03:07 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetState Sep 08 09:03:07 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:03:07 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 08 09:03:07 minidsp-shd volumio[839]: info: CoreCommandRouter::volumioGetState Sep 08 09:03:07 minidsp-shd volumio[839]: info: CorePlayQueue::getTrack 0 Sep 08 09:03:07 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 09:03:07 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Sep 08 09:03:07 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 09:03:07 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 09:03:07 minidsp-shd go-librespot[1405]: Librespot-go daemon starting... Sep 08 09:03:07 minidsp-shd go-librespot[1405]: time="2024-09-08T09:03:07-07:00" level=info msg="generated new device id: 2ba834f12f8c46eed535ce3126657181cf230b55" Sep 08 09:03:07 minidsp-shd go-librespot[1405]: time="2024-09-08T09:03:07-07:00" level=debug msg="stored credentials found for seyf1gokh2xqje3i089bqxgpz" Sep 08 09:03:07 minidsp-shd go-librespot[1405]: time="2024-09-08T09:03:07-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Sep 08 09:03:07 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 09:03:07 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 09:03:10 minidsp-shd volumio[839]: info: Initializing connection to go-librespot Websocket Sep 08 09:03:10 minidsp-shd volumio[839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 09:03:10 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 09:03:10 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Sep 08 09:03:10 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 09:03:10 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 09:03:10 minidsp-shd go-librespot[1414]: Librespot-go daemon starting... Sep 08 09:03:10 minidsp-shd go-librespot[1414]: time="2024-09-08T09:03:10-07:00" level=info msg="generated new device id: a5b62bde09ee9417bb6b02b17914b7d307683ad9" Sep 08 09:03:10 minidsp-shd go-librespot[1414]: time="2024-09-08T09:03:10-07:00" level=debug msg="stored credentials found for seyf1gokh2xqje3i089bqxgpz" Sep 08 09:03:10 minidsp-shd go-librespot[1414]: time="2024-09-08T09:03:10-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Sep 08 09:03:10 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 09:03:10 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 09:03:13 minidsp-shd volumio[839]: info: Initializing connection to go-librespot Websocket Sep 08 09:03:13 minidsp-shd volumio[839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 09:03:14 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 09:03:14 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Sep 08 09:03:14 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 09:03:14 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 09:03:14 minidsp-shd go-librespot[1422]: Librespot-go daemon starting... Sep 08 09:03:14 minidsp-shd go-librespot[1422]: time="2024-09-08T09:03:14-07:00" level=info msg="generated new device id: 03113adada448b7c065b3d23648bd986b9acd641" Sep 08 09:03:14 minidsp-shd go-librespot[1422]: time="2024-09-08T09:03:14-07:00" level=debug msg="stored credentials found for seyf1gokh2xqje3i089bqxgpz" Sep 08 09:03:14 minidsp-shd go-librespot[1422]: time="2024-09-08T09:03:14-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Sep 08 09:03:14 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 09:03:14 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 09:03:15 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: inputs , handleBrowseUri Sep 08 09:03:15 minidsp-shd volumio[839]: info: Preload queue cleared Sep 08 09:03:16 minidsp-shd volumio[839]: info: Initializing connection to go-librespot Websocket Sep 08 09:03:16 minidsp-shd volumio[839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 09:03:17 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 09:03:17 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Sep 08 09:03:17 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 09:03:17 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 09:03:17 minidsp-shd go-librespot[1429]: Librespot-go daemon starting... Sep 08 09:03:17 minidsp-shd go-librespot[1429]: time="2024-09-08T09:03:17-07:00" level=info msg="generated new device id: b4f65b53897cd7b44f1a5f51f247096c3d934eac" Sep 08 09:03:17 minidsp-shd go-librespot[1429]: time="2024-09-08T09:03:17-07:00" level=debug msg="stored credentials found for seyf1gokh2xqje3i089bqxgpz" Sep 08 09:03:17 minidsp-shd go-librespot[1429]: time="2024-09-08T09:03:17-07:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy" Sep 08 09:03:17 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Sep 08 09:03:17 minidsp-shd systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Sep 08 09:03:17 minidsp-shd ntpd[30790]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Sep 08 09:03:17 minidsp-shd ntpd[30790]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Sep 08 09:03:19 minidsp-shd volumio[839]: info: Initializing connection to go-librespot Websocket Sep 08 09:03:19 minidsp-shd volumio[839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Sep 08 09:03:19 minidsp-shd volumio[839]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Sep 08 09:03:19 minidsp-shd ntpd[30790]: ntpd exiting on signal 15 (Terminated) Sep 08 09:03:19 minidsp-shd volumio[839]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Sep 08 09:03:19 minidsp-shd systemd[1]: Stopping Network Time Service... Sep 08 09:03:19 minidsp-shd volumio[839]: ------------------------------------ BT MESSAGE: BT STATUS: running Sep 08 09:03:19 minidsp-shd systemd[1]: ntp.service: Succeeded. Sep 08 09:03:19 minidsp-shd systemd[1]: Stopped Network Time Service. Sep 08 09:03:19 minidsp-shd volumio[839]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Sep 08 09:03:19 minidsp-shd systemd[1]: Starting Network Time Service... Sep 08 09:03:19 minidsp-shd volumio[839]: ------------------------------------ BT MESSAGE: BT STATUS: running Sep 08 09:03:19 minidsp-shd ntpd[1500]: ntpd 4.2.8p12@1.3728-o (1): Starting Sep 08 09:03:19 minidsp-shd ntpd[1500]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Sep 08 09:03:19 minidsp-shd systemd[1]: Started Network Time Service. Sep 08 09:03:19 minidsp-shd ntpd[1506]: proto: precision = 1.250 usec (-20) Sep 08 09:03:19 minidsp-shd ntpd[1506]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Sep 08 09:03:19 minidsp-shd ntpd[1506]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Sep 08 09:03:19 minidsp-shd ntpd[1506]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 621 days ago Sep 08 09:03:19 minidsp-shd ntpd[1506]: Listen and drop on 0 v6wildcard [::]:123 Sep 08 09:03:19 minidsp-shd ntpd[1506]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Sep 08 09:03:19 minidsp-shd ntpd[1506]: Listen normally on 2 lo 127.0.0.1:123 Sep 08 09:03:19 minidsp-shd ntpd[1506]: Listen normally on 3 eth0 192.168.68.54:123 Sep 08 09:03:19 minidsp-shd ntpd[1506]: Listening on routing socket on fd #20 for interface updates Sep 08 09:03:19 minidsp-shd ntpd[1506]: kernel reports TIME_ERROR: 0x6041: Clock Unsynchronized Sep 08 09:03:19 minidsp-shd ntpd[1506]: kernel reports TIME_ERROR: 0x6041: Clock Unsynchronized Sep 08 09:03:20 minidsp-shd ntpd[1506]: Soliciting pool server 207.5.137.133 Sep 08 09:03:20 minidsp-shd systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Sep 08 09:03:20 minidsp-shd systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Sep 08 09:03:20 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 09:03:20 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 09:03:20 minidsp-shd go-librespot[1508]: Librespot-go daemon starting... Sep 08 09:03:20 minidsp-shd go-librespot[1508]: time="2024-09-08T09:03:20-07:00" level=info msg="generated new device id: 1aadcad4d81ee7237b2fb326184b6ab4562493c2" Sep 08 09:03:20 minidsp-shd go-librespot[1508]: time="2024-09-08T09:03:20-07:00" level=debug msg="stored credentials found for seyf1gokh2xqje3i089bqxgpz" Sep 08 09:03:21 minidsp-shd go-librespot[1508]: time="2024-09-08T09:03:21-07:00" level=debug msg="obtained new client token: AADKi0yn4tat/1aOvEVpuF9u2jCWTcT4qdfJvr4ahh7zqHwMbsg1VsE9aCwVd2H3ze+l6kdpQFO+JUjdHaDZZDWjApPw9sn3JlOVjgWqrXz0UMZx7rqkAEiT2oPpuP+GCXvTDUZPPY81MsYv+JldAn6w+zsZMtzvc4yS2ly0fCYjdW2YO0PfHthHm3rcHp4SCgUhzAaDG1/fn87ZugUhY4f5lXx33wdc0N8m+4XF6eIxVvze/DCQIsenG6N9cL4=" Sep 08 09:03:21 minidsp-shd go-librespot[1508]: time="2024-09-08T09:03:21-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 08 09:03:21 minidsp-shd go-librespot[1508]: time="2024-09-08T09:03:21-07:00" level=debug msg="completed keyexchange" Sep 08 09:03:21 minidsp-shd ntpd[1506]: Soliciting pool server 51.81.226.229 Sep 08 09:03:21 minidsp-shd ntpd[1506]: Soliciting pool server 129.250.35.250 Sep 08 09:03:21 minidsp-shd go-librespot[1508]: time="2024-09-08T09:03:21-07:00" level=debug msg="completed challenge" Sep 08 09:03:22 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Sep 08 09:03:22 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Sep 08 09:03:22 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Sep 08 09:03:22 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Sep 08 09:03:22 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Sep 08 09:03:22 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Sep 08 09:03:22 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Sep 08 09:03:22 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Sep 08 09:03:22 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Sep 08 09:03:22 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Sep 08 09:03:22 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Sep 08 09:03:22 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Sep 08 09:03:22 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Sep 08 09:03:22 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Sep 08 09:03:22 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Sep 08 09:03:22 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Sep 08 09:03:22 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Sep 08 09:03:22 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Sep 08 09:03:22 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Sep 08 09:03:22 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Sep 08 09:03:22 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Sep 08 09:03:22 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Sep 08 09:03:22 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Sep 08 09:03:22 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Sep 08 09:03:22 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Sep 08 09:03:22 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Sep 08 09:03:22 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Sep 08 09:03:22 minidsp-shd go-librespot[1508]: time="2024-09-08T09:03:22-07:00" level=debug msg="authenticated as seyf1gokh2xqje3i089bqxgpz" Sep 08 09:03:22 minidsp-shd go-librespot[1508]: time="2024-09-08T09:03:22-07:00" level=debug msg="authenticated as seyf1gokh2xqje3i089bqxgpz" Sep 08 09:03:22 minidsp-shd go-librespot[1508]: time="2024-09-08T09:03:22-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 08 09:03:22 minidsp-shd ntpd[1506]: Soliciting pool server 135.148.100.14 Sep 08 09:03:22 minidsp-shd ntpd[1506]: Soliciting pool server 104.167.241.253 Sep 08 09:03:22 minidsp-shd go-librespot[1508]: time="2024-09-08T09:03:22-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Sep 08 09:03:22 minidsp-shd ntpd[1506]: Soliciting pool server 129.146.193.200 Sep 08 09:03:22 minidsp-shd go-librespot[1508]: time="2024-09-08T09:03:22-07:00" level=debug msg="dealer connection opened" Sep 08 09:03:22 minidsp-shd go-librespot[1508]: time="2024-09-08T09:03:22-07:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Sep 08 09:03:22 minidsp-shd go-librespot[1508]: time="2024-09-08T09:03:22-07:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Sep 08 09:03:22 minidsp-shd go-librespot[1508]: time="2024-09-08T09:03:22-07:00" level=debug msg="received connection id: MWNkZDRhYWMtZTI5Ni00NmZmLTg1ZDgtZTY3YTQxODkyODFjK2RlYWxlcit0Y3A6Ly8wYWNiZDgwYS5pcC5ndWMzLnNwb3RpZnkubmV0OjU3MDArMUFBMTEyMDZBNUE3QkU1NjNGOERBQjc5NDhGNDk3MEE0N0ZBNDc2QjgyRjM1OTkyNjk1NjAxN0RBQ0U3NzZDMA==" Sep 08 09:03:22 minidsp-shd go-librespot[1508]: time="2024-09-08T09:03:22-07:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Sep 08 09:03:22 minidsp-shd go-librespot[1508]: time="2024-09-08T09:03:22-07:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Sep 08 09:03:22 minidsp-shd go-librespot[1508]: time="2024-09-08T09:03:22-07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513" Sep 08 09:03:22 minidsp-shd go-librespot[1508]: time="2024-09-08T09:03:22-07:00" level=debug msg="put connect state because NEW_DEVICE" Sep 08 09:03:23 minidsp-shd ntpd[1506]: Soliciting pool server 142.202.190.19 Sep 08 09:03:23 minidsp-shd ntpd[1506]: Soliciting pool server 71.162.136.44 Sep 08 09:03:23 minidsp-shd ntpd[1506]: Soliciting pool server 23.168.136.132 Sep 08 09:03:23 minidsp-shd ntpd[1506]: Soliciting pool server 198.137.202.56 Sep 08 09:03:23 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Sep 08 09:03:23 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Sep 08 09:03:23 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 08 09:03:23 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 08 09:03:23 minidsp-shd volumio[839]: info: Starting MyVolumio Remote Streaming Endpoints Sep 08 09:03:23 minidsp-shd volumio[839]: info: MyVolumio login type: Token Sep 08 09:03:23 minidsp-shd volumio[839]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Sep 08 09:03:23 minidsp-shd volumio[839]: error: [MyVolumio PluginManager] Could not read package.json file: Error: /myvolumio/plugins/music_service/streaming_services//package.json: ENOENT: no such file or directory, open '/myvolumio/plugins/music_service/streaming_services//package.json' Sep 08 09:03:23 minidsp-shd volumio[839]: info: Initializing connection to go-librespot Websocket Sep 08 09:03:23 minidsp-shd go-librespot[1508]: time="2024-09-08T09:03:23-07:00" level=debug msg="new websocket client" Sep 08 09:03:23 minidsp-shd volumio[839]: info: Connection to go-librespot Websocket established Sep 08 09:03:23 minidsp-shd volumio[839]: error: MyVolumio Custom Token format not valid, refreshing it Sep 08 09:03:24 minidsp-shd ntpd[1506]: Soliciting pool server 216.31.17.12 Sep 08 09:03:24 minidsp-shd ntpd[1506]: Soliciting pool server 44.190.5.123 Sep 08 09:03:24 minidsp-shd ntpd[1506]: Soliciting pool server 50.218.103.254 Sep 08 09:03:24 minidsp-shd volumio[839]: info: MyVolumio login type: Token Sep 08 09:03:24 minidsp-shd ntpd[1506]: Soliciting pool server 155.138.194.125 Sep 08 09:03:24 minidsp-shd volumio[839]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Sep 08 09:03:25 minidsp-shd volumio[839]: Searching all installed plugins Sep 08 09:03:25 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 08 09:03:25 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: , search Sep 08 09:03:25 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: mpd , search Sep 08 09:03:25 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Sep 08 09:03:25 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Sep 08 09:03:25 minidsp-shd volumio[839]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Sep 08 09:03:25 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: webradio , search Sep 08 09:03:25 minidsp-shd volumio[839]: info: CoreCommandRouter::executeOnPlugin: calmradio , search Sep 08 09:03:25 minidsp-shd volumio[839]: info: [1725811405461] ControllerCalmRadio::searchCategories Sep 08 09:03:25 minidsp-shd volumio[839]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 08 09:03:25 minidsp-shd volumio[839]: TypeError: Cannot read property 'cats' of undefined Sep 08 09:03:25 minidsp-shd volumio[839]: at ControllerCalmRadio.searchCategories (/data/plugins/music_service/calmradio/index.js:615:42) Sep 08 09:03:25 minidsp-shd volumio[839]: at ControllerCalmRadio.search (/data/plugins/music_service/calmradio/index.js:665:28) Sep 08 09:03:25 minidsp-shd volumio[839]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1077:32) Sep 08 09:03:25 minidsp-shd volumio[839]: at CoreMusicLibrary.searchOnPlugin (/volumio/app/musiclibrary.js:668:44) Sep 08 09:03:25 minidsp-shd volumio[839]: at CoreMusicLibrary.search (/volumio/app/musiclibrary.js:455:27) Sep 08 09:03:25 minidsp-shd volumio[839]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:457:44) Sep 08 09:03:25 minidsp-shd volumio[839]: at Socket.emit (events.js:400:28) Sep 08 09:03:25 minidsp-shd volumio[839]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Sep 08 09:03:25 minidsp-shd volumio[839]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Sep 08 09:03:25 minidsp-shd volumio[839]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 08 09:03:25 minidsp-shd ntpd[1506]: Soliciting pool server 137.190.2.4 Sep 08 09:03:25 minidsp-shd ntpd[1506]: Soliciting pool server 2001:559:2be:3::1001 Sep 08 09:03:25 minidsp-shd ntpd[1506]: Soliciting pool server 108.181.201.22 Sep 08 09:03:26 minidsp-shd sudo[1526]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-09-08 09:02 Sep 08 09:03:26 minidsp-shd sudo[1526]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:03:26 minidsp-shd sudo[1526]: pam_unix(sudo:session): session closed for user root Sep 08 09:03:26 minidsp-shd ntpd[1506]: Soliciting pool server 23.150.41.123 Sep 08 09:03:26 minidsp-shd ntpd[1506]: Soliciting pool server 72.46.53.234 Sep 08 09:03:27 minidsp-shd vtcs[1174]: [2024-09-08 09:03:27.490] [tisoc] [error] [SpkconServer.cpp:377] recv error. socket disconnected Sep 08 09:03:27 minidsp-shd volumio-remote-updater[455]: [2024-09-08 09:03:27] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Sep 08 09:03:27 minidsp-shd volumio-remote-updater[455]: [2024-09-08 09:03:27] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Sep 08 09:03:27 minidsp-shd systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Sep 08 09:03:27 minidsp-shd go-librespot[1508]: time="2024-09-08T09:03:27-07:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Sep 08 09:03:27 minidsp-shd systemd[1]: volumio.service: Failed with result 'exit-code'. Sep 08 09:03:27 minidsp-shd systemd[1]: Started dynamicswap service. Sep 08 09:03:27 minidsp-shd systemd[1]: dynamicswap.service: Succeeded. Sep 08 09:03:27 minidsp-shd systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Sep 08 09:03:27 minidsp-shd systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2. Sep 08 09:03:27 minidsp-shd systemd[1]: Stopped Volumio Backend Module. Sep 08 09:03:27 minidsp-shd systemd[1]: Started Volumio Backend Module. Sep 08 09:03:27 minidsp-shd systemd[1]: Started dynamicswap service. Sep 08 09:03:27 minidsp-shd systemd[1]: dynamicswap.service: Succeeded. Sep 08 09:03:30 minidsp-shd volumio[1539]: info: ------------------------------------------- Sep 08 09:03:30 minidsp-shd volumio[1539]: info: ----- Volumio3 ---- Sep 08 09:03:30 minidsp-shd volumio[1539]: info: ------------------------------------------- Sep 08 09:03:30 minidsp-shd volumio[1539]: info: ----- System startup ---- Sep 08 09:03:30 minidsp-shd volumio[1539]: info: ------------------------------------------- Sep 08 09:03:31 minidsp-shd volumio[1539]: info: MYVOLUMIO Environment detected Sep 08 09:03:31 minidsp-shd volumio[1539]: info: Plugin folders cleanup Sep 08 09:03:31 minidsp-shd volumio[1539]: info: Scanning into folder /volumio/app/plugins/ Sep 08 09:03:31 minidsp-shd volumio[1539]: info: Scanning category audio_interface Sep 08 09:03:31 minidsp-shd volumio[1539]: info: Scanning category miscellanea Sep 08 09:03:31 minidsp-shd volumio[1539]: info: Scanning category music_service Sep 08 09:03:31 minidsp-shd volumio[1539]: info: Scanning category plugins.json Sep 08 09:03:31 minidsp-shd volumio[1539]: info: Scanning category system_controller Sep 08 09:03:31 minidsp-shd volumio[1539]: info: Scanning category user_interface Sep 08 09:03:31 minidsp-shd volumio[1539]: info: Scanning into folder /data/plugins/ Sep 08 09:03:31 minidsp-shd volumio[1539]: info: Scanning category music_service Sep 08 09:03:31 minidsp-shd volumio[1539]: info: Plugin folders cleanup completed Sep 08 09:03:31 minidsp-shd volumio[1539]: info: ------------------------------------------- Sep 08 09:03:31 minidsp-shd volumio[1539]: info: ----- Core plugins startup ---- Sep 08 09:03:31 minidsp-shd volumio[1539]: info: ------------------------------------------- Sep 08 09:03:31 minidsp-shd volumio[1539]: info: Loading plugins from folder /volumio/app/plugins/ Sep 08 09:03:31 minidsp-shd volumio[1539]: info: Adding plugin bluetooth to MyMusic Plugins Sep 08 09:03:31 minidsp-shd volumio[1539]: info: Adding plugin multiroom to MyMusic Plugins Sep 08 09:03:31 minidsp-shd volumio[1539]: info: Adding plugin upnp to MyMusic Plugins Sep 08 09:03:31 minidsp-shd volumio[1539]: info: Adding plugin metavolumio to MyMusic Plugins Sep 08 09:03:31 minidsp-shd volumio[1539]: info: Adding plugin ms_surface_dial to MyMusic Plugins Sep 08 09:03:31 minidsp-shd volumio[1539]: info: Adding plugin airplay_emulation to MyMusic Plugins Sep 08 09:03:31 minidsp-shd volumio[1539]: info: Adding plugin cd_controller to MyMusic Plugins Sep 08 09:03:31 minidsp-shd volumio[1539]: info: Adding plugin raat to MyMusic Plugins Sep 08 09:03:31 minidsp-shd volumio[1539]: info: Adding plugin tidalconnect to MyMusic Plugins Sep 08 09:03:31 minidsp-shd volumio[1539]: info: Adding plugin upnp_browser to MyMusic Plugins Sep 08 09:03:31 minidsp-shd volumio[1539]: info: Loading plugins from folder /data/plugins/ Sep 08 09:03:31 minidsp-shd volumio[1539]: info: Loading plugin "system"... Sep 08 09:03:31 minidsp-shd volumio[1539]: info: Loading plugin "appearance"... Sep 08 09:03:32 minidsp-shd volumio-remote-updater[455]: [2024-09-08 09:03:32] [connect] Successful connection Sep 08 09:03:32 minidsp-shd volumio[1539]: info: Loading plugin "network"... Sep 08 09:03:32 minidsp-shd volumio[1539]: info: Refreshing Cached IP Addresses Sep 08 09:03:32 minidsp-shd sudo[1567]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 08 09:03:32 minidsp-shd sudo[1567]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:03:32 minidsp-shd sudo[1567]: pam_unix(sudo:session): session closed for user root Sep 08 09:03:32 minidsp-shd sudo[1569]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 08 09:03:32 minidsp-shd sudo[1569]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:03:32 minidsp-shd volumio[1539]: info: Loading plugin "services"... Sep 08 09:03:32 minidsp-shd volumio[1539]: info: Loading plugin "alsa_controller"... Sep 08 09:03:32 minidsp-shd sudo[1572]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 08 09:03:32 minidsp-shd sudo[1572]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:03:33 minidsp-shd sudo[1569]: pam_unix(sudo:session): session closed for user root Sep 08 09:03:33 minidsp-shd sudo[1572]: pam_unix(sudo:session): session closed for user root Sep 08 09:03:33 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 08 09:03:33 minidsp-shd volumio[1539]: info: Loading plugin "wizard"... Sep 08 09:03:33 minidsp-shd volumio[1539]: info: Loading plugin "networkfs"... Sep 08 09:03:33 minidsp-shd volumio[1539]: info: Starting Udev Watcher for removable devices Sep 08 09:03:33 minidsp-shd volumio[1539]: info: Ignoring mount for partition: BOOT Sep 08 09:03:33 minidsp-shd volumio[1539]: info: Ignoring mount for partition: volumio Sep 08 09:03:33 minidsp-shd volumio[1539]: info: Ignoring mount for partition: volumio_data Sep 08 09:03:33 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 08 09:03:33 minidsp-shd volumio[1539]: info: Loading plugin "volumio_command_line_client"... Sep 08 09:03:33 minidsp-shd volumio[1539]: info: Loading plugin "upnp"... Sep 08 09:03:33 minidsp-shd volumio[1539]: info: [1725811413201] Starting Upmpd Daemon Sep 08 09:03:33 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 08 09:03:33 minidsp-shd volumio[1539]: info: Loading plugin "my_music"... Sep 08 09:03:33 minidsp-shd volumio[1539]: info: Loading plugin "mpd"... Sep 08 09:03:33 minidsp-shd volumio[1539]: info: Loading plugin "upnp_browser"... Sep 08 09:03:34 minidsp-shd volumio[1539]: info: Loading plugin "bluetooth"... Sep 08 09:03:34 minidsp-shd volumio[1539]: info: [1725811414351] Starting BluetoothController Sep 08 09:03:34 minidsp-shd volumio[1539]: info: Loading plugin "alarm-clock"... Sep 08 09:03:34 minidsp-shd volumio[1539]: info: Loading plugin "manifestui"... Sep 08 09:03:34 minidsp-shd volumio[1539]: info: Loading plugin "metavolumio"... Sep 08 09:03:36 minidsp-shd volumio[1539]: info: Loading plugin "airplay_emulation"... Sep 08 09:03:36 minidsp-shd volumio[1539]: info: Starting Shairport Sync Sep 08 09:03:36 minidsp-shd volumio[1539]: info: Loading plugin "cd_controller"... Sep 08 09:03:36 minidsp-shd volumio[1539]: info: Loading plugin "last_100"... Sep 08 09:03:36 minidsp-shd volumio[1539]: info: Loading plugin "raat"... Sep 08 09:03:36 minidsp-shd volumio[1539]: info: RAAT Plugin loaded Sep 08 09:03:36 minidsp-shd volumio[1539]: info: Adding restartRAATSocket REST API Endpoint Sep 08 09:03:36 minidsp-shd volumio[1539]: info: Adding restartRAATSocket REST Endpoint for plugin: music_service/raat Sep 08 09:03:36 minidsp-shd volumio[1539]: info: Loading plugin "streaming_services"... Sep 08 09:03:38 minidsp-shd volumio[1539]: info: Starting Streaming Service Transparent Proxy Sep 08 09:03:38 minidsp-shd volumio[1539]: info: Loading plugin "tidalconnect"... Sep 08 09:03:38 minidsp-shd volumio[1539]: info: Loading plugin "webradio"... Sep 08 09:03:38 minidsp-shd volumio[1539]: info: Loading plugin "i2s_dacs"... Sep 08 09:03:38 minidsp-shd volumio[1539]: info: I2S DAC not set, start Auto-detection Sep 08 09:03:38 minidsp-shd volumio[1539]: info: Loading plugin "volumiodiscovery"... Sep 08 09:03:38 minidsp-shd volumio[1539]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 08 09:03:38 minidsp-shd volumio[1539]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 08 09:03:38 minidsp-shd volumio[1539]: *** WARNING *** For more information see Sep 08 09:03:38 minidsp-shd volumio[1539]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 08 09:03:38 minidsp-shd node[1539]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 08 09:03:38 minidsp-shd volumio[1539]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 08 09:03:38 minidsp-shd volumio[1539]: *** WARNING *** For more information see Sep 08 09:03:38 minidsp-shd node[1539]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 08 09:03:38 minidsp-shd node[1539]: *** WARNING *** For more information see Sep 08 09:03:38 minidsp-shd node[1539]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 08 09:03:38 minidsp-shd node[1539]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 08 09:03:38 minidsp-shd node[1539]: *** WARNING *** For more information see Sep 08 09:03:38 minidsp-shd volumio[1539]: info: Applying required configuration parameters for plugin volumiodiscovery Sep 08 09:03:38 minidsp-shd volumio[1539]: info: Discovery: Started advertising with name: miniDSP SHD Sep 08 09:03:38 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 08 09:03:38 minidsp-shd volumio[1539]: info: Loading plugin "calmradio"... Sep 08 09:03:39 minidsp-shd volumio[1539]: STREAMING PROXY: Starting server on port 3245 Sep 08 09:03:39 minidsp-shd volumio[1539]: Node JS runtime: 14 Sep 08 09:03:39 minidsp-shd volumio[1539]: info: Loading plugin "spop"... Sep 08 09:03:41 minidsp-shd volumio[1539]: info: Loading plugin "youtube2"... Sep 08 09:03:42 minidsp-shd volumio[1539]: info: Plugin multiroom is not enabled Sep 08 09:03:42 minidsp-shd volumio[1539]: info: Loading plugin "outputs"... Sep 08 09:03:42 minidsp-shd volumio[1539]: info: Loading plugin "albumart"... Sep 08 09:03:42 minidsp-shd volumio[1539]: info: Loading plugin "ms_surface_dial"... Sep 08 09:03:43 minidsp-shd volumio[1539]: Forking 3 albumart workers Sep 08 09:03:43 minidsp-shd volumio[1539]: info: Applying required configuration parameters for plugin ms_surface_dial Sep 08 09:03:43 minidsp-shd volumio[1539]: info: Plugin example_plugin is not enabled Sep 08 09:03:43 minidsp-shd volumio[1539]: info: Loading plugin "hi_res_audio"... Sep 08 09:03:44 minidsp-shd volumio[1539]: Starting albumart workers Sep 08 09:03:44 minidsp-shd volumio[1539]: Starting albumart workers Sep 08 09:03:44 minidsp-shd volumio[1539]: Starting albumart workers Sep 08 09:03:44 minidsp-shd volumio-remote-updater[455]: [2024-09-08 09:03:44] [connect] Successful connection Sep 08 09:03:45 minidsp-shd volumio[1539]: info: Applying required configuration parameters for plugin hi_res_audio Sep 08 09:03:45 minidsp-shd volumio[1539]: info: Loading plugin "inputs"... Sep 08 09:03:46 minidsp-shd volumio[1539]: info: Loading plugin "qobuz"... Sep 08 09:03:47 minidsp-shd volumio[1539]: info: Loading plugin "tidal"... Sep 08 09:03:48 minidsp-shd volumio[1539]: info: Loading plugin "oem_helper"... Sep 08 09:03:49 minidsp-shd volumio[1539]: info: Applying required configuration parameters for plugin oem_helper Sep 08 09:03:49 minidsp-shd volumio[1539]: info: Loading plugin "updater_comm"... Sep 08 09:03:50 minidsp-shd volumio[1539]: info: Plugin mpdemulation is not enabled Sep 08 09:03:50 minidsp-shd volumio[1539]: info: Loading plugin "rest_api"... Sep 08 09:03:50 minidsp-shd volumio[1539]: info: Loading plugin "websocket"... Sep 08 09:03:50 minidsp-shd volumio[1539]: info: Loading plugin "motherearthradio"... Sep 08 09:03:50 minidsp-shd volumio[1539]: info: Applying required configuration parameters for plugin motherearthradio Sep 08 09:03:50 minidsp-shd volumio[1539]: info: [1725811430474] [MotherEarth] API delay: 5 Sep 08 09:03:50 minidsp-shd volumio[1539]: info: Loading i18n strings for locale en Sep 08 09:03:50 minidsp-shd volumio[1539]: Updating browse sources language Sep 08 09:03:50 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 08 09:03:50 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 08 09:03:50 minidsp-shd volumio[1539]: info: CoreCommandRouter::initPlayerControls Sep 08 09:03:50 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:50 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:50 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:50 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:50 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:50 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:50 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:50 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:50 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 08 09:03:50 minidsp-shd volumio[1539]: Express server listening on port 3000 Sep 08 09:03:50 minidsp-shd volumio[1539]: [Metrics] WebUI: 21s 201.79ms Sep 08 09:03:50 minidsp-shd volumio[1539]: info: CoreStateMachine::resetVolumioState Sep 08 09:03:50 minidsp-shd volumio[1539]: info: CoreStateMachine::getcurrentVolume Sep 08 09:03:50 minidsp-shd volumio[1539]: info: CoreCommandRouter::volumioRetrievevolume Sep 08 09:03:50 minidsp-shd volumio[1539]: info: CoreStateMachine::pushState Sep 08 09:03:50 minidsp-shd volumio[1539]: info: CorePlayQueue::getTrack 0 Sep 08 09:03:50 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 08 09:03:50 minidsp-shd volumio[1539]: info: CoreCommandRouter::volumioPushState Sep 08 09:03:50 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 08 09:03:50 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: inputs , getVolume Sep 08 09:03:50 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: inputs , getDSP Sep 08 09:03:50 minidsp-shd sudo[1651]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 08 09:03:50 minidsp-shd sudo[1651]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:03:50 minidsp-shd sudo[1651]: pam_unix(sudo:session): session closed for user root Sep 08 09:03:50 minidsp-shd sudo[1654]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 08 09:03:50 minidsp-shd sudo[1654]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:03:50 minidsp-shd volumio[1539]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Sep 08 09:03:50 minidsp-shd volumio[1539]: info: Completed loading Core Plugins Sep 08 09:03:50 minidsp-shd volumio[1539]: info: Preparing to generate the ALSA configuration file Sep 08 09:03:51 minidsp-shd sudo[1654]: pam_unix(sudo:session): session closed for user root Sep 08 09:03:51 minidsp-shd volumio[1539]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Sep 08 09:03:51 minidsp-shd volumio[1539]: wlan0 Interface doesn't support scanning. Sep 08 09:03:51 minidsp-shd volumio[1539]: info: Cannot use regular scanning, forcing with ap-force Sep 08 09:03:51 minidsp-shd sudo[1659]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Sep 08 09:03:51 minidsp-shd sudo[1659]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:03:51 minidsp-shd sudo[1659]: pam_unix(sudo:session): session closed for user root Sep 08 09:03:51 minidsp-shd volumio[1539]: command failed: No such device (-19) Sep 08 09:03:51 minidsp-shd volumio[1539]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Sep 08 09:03:51 minidsp-shd volumio[1539]: command failed: No such device (-19) Sep 08 09:03:51 minidsp-shd volumio[1539]: verbose: New Socket.io Connection to 192.168.68.54 from 192.168.68.65 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.6 Mobile/15E148 Safari/604.1 Total Clients: 1 Sep 08 09:03:51 minidsp-shd volumio[1539]: verbose: New Socket.io Connection to 192.168.68.54 from 192.168.68.65 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.6 Mobile/15E148 Safari/604.1 Total Clients: 2 Sep 08 09:03:51 minidsp-shd volumio[1539]: verbose: New Socket.io Connection to 192.168.68.54 from 192.168.68.65 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.6 Mobile/15E148 Safari/604.1 Total Clients: 3 Sep 08 09:03:51 minidsp-shd volumio[1539]: verbose: New Socket.io Connection to 192.168.68.54 from 192.168.68.65 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.6 Mobile/15E148 Safari/604.1 Total Clients: 4 Sep 08 09:03:51 minidsp-shd volumio[1539]: verbose: New Socket.io Connection to 192.168.68.54 from 192.168.68.65 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.6 Mobile/15E148 Safari/604.1 Total Clients: 5 Sep 08 09:03:51 minidsp-shd volumio[1539]: info: Asound.conf file unchanged, so no further update is needed Sep 08 09:03:51 minidsp-shd volumio[1539]: info: Output device has changed, restarting MPD Sep 08 09:03:51 minidsp-shd sudo[1669]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 08 09:03:51 minidsp-shd sudo[1669]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:03:51 minidsp-shd sudo[1669]: pam_unix(sudo:session): session closed for user root Sep 08 09:03:51 minidsp-shd volumio[1539]: info: Output device has changed, restarting Shairport Sync Sep 08 09:03:51 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:51 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 08 09:03:51 minidsp-shd sudo[1672]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 08 09:03:51 minidsp-shd sudo[1672]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:03:51 minidsp-shd systemd[1]: Stopping Music Player Daemon... Sep 08 09:03:51 minidsp-shd volumio[1539]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 08 09:03:51 minidsp-shd volumio[1539]: info: ___________ START PLUGINS ___________ Sep 08 09:03:51 minidsp-shd volumio[1539]: info: ControllerMpd::onStart: Initializing MPD Sep 08 09:03:51 minidsp-shd volumio[1539]: info: Creating MPD Configuration file Sep 08 09:03:51 minidsp-shd systemd[1]: mpd.service: Succeeded. Sep 08 09:03:51 minidsp-shd systemd[1]: Stopped Music Player Daemon. Sep 08 09:03:51 minidsp-shd sudo[1678]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 08 09:03:51 minidsp-shd systemd[1]: Starting Music Player Daemon... Sep 08 09:03:51 minidsp-shd sudo[1678]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:03:51 minidsp-shd sudo[1678]: pam_unix(sudo:session): session closed for user root Sep 08 09:03:51 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 08 09:03:51 minidsp-shd volumio[1539]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 08 09:03:51 minidsp-shd volumio[1539]: info: [1725811431757] CoreMusicLibrary::Adding element Media Servers Sep 08 09:03:51 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 08 09:03:51 minidsp-shd sudo[1682]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 08 09:03:51 minidsp-shd sudo[1682]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:03:51 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 08 09:03:51 minidsp-shd systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Sep 08 09:03:51 minidsp-shd systemd[1]: mpd.service: Succeeded. Sep 08 09:03:51 minidsp-shd systemd[1]: Stopped Music Player Daemon. Sep 08 09:03:51 minidsp-shd systemd[1]: Starting Music Player Daemon... Sep 08 09:03:51 minidsp-shd volumio[1539]: info: Adding Manifest REST API Endpoints Sep 08 09:03:51 minidsp-shd volumio[1539]: info: Adding manifestui REST Endpoint for plugin: miscellanea/manifestui Sep 08 09:03:51 minidsp-shd volumio[1539]: info: Adding METAVOLUMIO REST API Endpoints Sep 08 09:03:51 minidsp-shd volumio[1539]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Sep 08 09:03:51 minidsp-shd volumio[1539]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Sep 08 09:03:51 minidsp-shd volumio[1539]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Sep 08 09:03:51 minidsp-shd volumio[1539]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Sep 08 09:03:51 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:51 minidsp-shd sudo[1686]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name miniDSP SHD Sep 08 09:03:51 minidsp-shd sudo[1686]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:03:51 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 08 09:03:51 minidsp-shd sudo[1686]: pam_unix(sudo:session): session closed for user root Sep 08 09:03:51 minidsp-shd volumio[1539]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 08 09:03:51 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:51 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 08 09:03:52 minidsp-shd volumio[1539]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 08 09:03:52 minidsp-shd volumio[1539]: info: Preparing CD Folders Sep 08 09:03:52 minidsp-shd volumio[1539]: info: Adding CD REST API Endpoints Sep 08 09:03:52 minidsp-shd volumio[1539]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Sep 08 09:03:52 minidsp-shd volumio[1539]: info: Starting UDEV Watcher for CD Sep 08 09:03:52 minidsp-shd volumio[1539]: info: Detecting CD presence with UDEV Sep 08 09:03:52 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Sep 08 09:03:52 minidsp-shd volumio[1539]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 08 09:03:52 minidsp-shd volumio[1539]: info: [1725811432070] CoreMusicLibrary::Adding element Last_100 Sep 08 09:03:52 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 08 09:03:52 minidsp-shd volumio[1539]: info: Starting RAAT Plugin Sep 08 09:03:52 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections Sep 08 09:03:52 minidsp-shd volumio[1539]: info: Additional UI Settings Added for plugin music_service/raat Sep 08 09:03:52 minidsp-shd volumio[1539]: info: Streaming services startup Sep 08 09:03:52 minidsp-shd volumio[1539]: info: Starting Streaming Daemon Sep 08 09:03:52 minidsp-shd sudo[1696]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Sep 08 09:03:52 minidsp-shd sudo[1696]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:03:52 minidsp-shd sudo[1696]: pam_unix(sudo:session): session closed for user root Sep 08 09:03:52 minidsp-shd volumio[1539]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 08 09:03:52 minidsp-shd volumio[1539]: info: [1725811432240] CoreMusicLibrary::Adding element Webradio Sep 08 09:03:52 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 08 09:03:52 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 08 09:03:52 minidsp-shd sudo[1703]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Sep 08 09:03:52 minidsp-shd volumio[1539]: info: Adding Calm Radio to Browse Sources Sep 08 09:03:52 minidsp-shd sudo[1703]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:03:52 minidsp-shd volumio[1539]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 08 09:03:52 minidsp-shd volumio[1539]: info: [1725811432265] CoreMusicLibrary::Adding element Calm Radio Sep 08 09:03:52 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 08 09:03:52 minidsp-shd volumio[1539]: Cannot find translation for source Calm Radio Sep 08 09:03:52 minidsp-shd volumio[1539]: info: Creating Spotify config file Sep 08 09:03:52 minidsp-shd systemd[1]: Stopping Volumio Tidal Connect Service... Sep 08 09:03:52 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:52 minidsp-shd systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM Sep 08 09:03:52 minidsp-shd systemd[1]: vtcs.service: Succeeded. Sep 08 09:03:52 minidsp-shd systemd[1]: Stopped Volumio Tidal Connect Service. Sep 08 09:03:52 minidsp-shd sudo[1703]: pam_unix(sudo:session): session closed for user root Sep 08 09:03:52 minidsp-shd volumio[1539]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 08 09:03:52 minidsp-shd volumio[1539]: info: [1725811432444] CoreMusicLibrary::Adding element YouTube2 Sep 08 09:03:52 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 08 09:03:52 minidsp-shd volumio[1539]: Cannot find translation for source Calm Radio Sep 08 09:03:52 minidsp-shd volumio[1539]: Cannot find translation for source YouTube2 Sep 08 09:03:52 minidsp-shd volumio[1539]: error: Hi Res Audio Failed Login: Missing Login Data Sep 08 09:03:52 minidsp-shd volumio[1539]: info: Adding HIGHRESAUDIO REST API Endpoints Sep 08 09:03:52 minidsp-shd volumio[1539]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Sep 08 09:03:52 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 08 09:03:52 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 08 09:03:52 minidsp-shd volumio[1539]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 08 09:03:52 minidsp-shd volumio[1539]: info: [1725811432623] CoreMusicLibrary::Adding element Mother Earth Radio Sep 08 09:03:52 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 08 09:03:52 minidsp-shd volumio[1539]: Cannot find translation for source Calm Radio Sep 08 09:03:52 minidsp-shd volumio[1539]: Cannot find translation for source YouTube2 Sep 08 09:03:52 minidsp-shd volumio[1539]: Cannot find translation for source Mother Earth Radio Sep 08 09:03:52 minidsp-shd volumio[1539]: info: Volumio Calling Home Sep 08 09:03:52 minidsp-shd volumio[1539]: info: Stopping AccessToken refresher cron for QOBUZ Sep 08 09:03:52 minidsp-shd volumio[1539]: info: AccessToken refresher cron started for QOBUZ Sep 08 09:03:52 minidsp-shd volumio[1539]: info: Stopping AccessToken refresher cron Sep 08 09:03:52 minidsp-shd volumio[1539]: info: AccessToken refresher cron started Sep 08 09:03:52 minidsp-shd volumio[1539]: info: Adding TIDAL REST API Endpoints Sep 08 09:03:52 minidsp-shd volumio[1539]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Sep 08 09:03:52 minidsp-shd volumio[1539]: info: Adding QOBUZ REST API Endpoints Sep 08 09:03:52 minidsp-shd volumio[1539]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreStateMachine::setRepeat false single undefined Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreStateMachine::pushState Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CorePlayQueue::getTrack 0 Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::volumioPushState Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreStateMachine::setRandom true Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreStateMachine::pushState Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CorePlayQueue::getTrack 0 Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::volumioPushState Sep 08 09:03:53 minidsp-shd volumio[1539]: info: Setting Device type: NanoPi NEO 2 Sep 08 09:03:53 minidsp-shd volumio[1539]: info: Serial port opened successfully Sep 08 09:03:53 minidsp-shd volumio[1539]: error: Cannot start Volumio Streaming Daemon Sep 08 09:03:53 minidsp-shd volumio[1539]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Sep 08 09:03:53 minidsp-shd volumio[1539]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Sep 08 09:03:53 minidsp-shd volumio[1539]: error: Cannot set new Bluetooth Name : Error: Command failed: /usr/bin/sudo /bin/hciconfig hci0 name 'miniDSP SHD' Sep 08 09:03:53 minidsp-shd volumio[1539]: Can't get device info: No such device Sep 08 09:03:53 minidsp-shd volumio[1539]: info: MPD Permissions set Sep 08 09:03:53 minidsp-shd volumio[1539]: info: MPD Permissions set Sep 08 09:03:53 minidsp-shd volumio[1539]: info: msSurfaceDial Managed Objs {"/org/bluez":{"org.freedesktop.DBus.Introspectable":{},"org.bluez.AgentManager1":{},"org.bluez.ProfileManager1":{}}} Sep 08 09:03:53 minidsp-shd volumio[1539]: info: [msSurfaceDial init()] check /org/bluez Sep 08 09:03:53 minidsp-shd volumio[1539]: info: [msSurfaceDial init()] Adapter: null; SurfaceDial: null Sep 08 09:03:53 minidsp-shd sudo[1721]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Sep 08 09:03:53 minidsp-shd sudo[1721]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:03:53 minidsp-shd volumio[1539]: info: msSurfaceDial BluetoothSurfaceDial init() - ready! Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::Reload Ui Sep 08 09:03:53 minidsp-shd sudo[1721]: pam_unix(sudo:session): session closed for user root Sep 08 09:03:53 minidsp-shd volumio[1539]: info: Volumio called home Sep 08 09:03:53 minidsp-shd volumio[1539]: info: Spotify config file written Sep 08 09:03:53 minidsp-shd sudo[1724]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Sep 08 09:03:53 minidsp-shd sudo[1724]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:03:53 minidsp-shd systemd[1]: Stopping go-librespot Daemon... Sep 08 09:03:53 minidsp-shd systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Sep 08 09:03:53 minidsp-shd systemd[1]: go-librespot-daemon.service: Succeeded. Sep 08 09:03:53 minidsp-shd systemd[1]: Stopped go-librespot Daemon. Sep 08 09:03:53 minidsp-shd systemd[1]: Started go-librespot Daemon. Sep 08 09:03:53 minidsp-shd volumio[1539]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 6 Sep 08 09:03:53 minidsp-shd go-librespot[1726]: Librespot-go daemon starting... Sep 08 09:03:53 minidsp-shd volumio[1539]: info: Upmpdcli Daemon Started Sep 08 09:03:53 minidsp-shd sudo[1724]: pam_unix(sudo:session): session closed for user root Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:53 minidsp-shd go-librespot[1726]: time="2024-09-08T09:03:53-07:00" level=info msg="generated new device id: a2fe3c4604a83701c5521407c4438b525b4dd1ba" Sep 08 09:03:53 minidsp-shd go-librespot[1726]: time="2024-09-08T09:03:53-07:00" level=debug msg="stored credentials found for seyf1gokh2xqje3i089bqxgpz" Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:53 minidsp-shd volumio[1539]: info: msSurfaceDial volumioupdatevolume callback: {"vol":57,"dbVolume":-55,"disableVolumeControl":false} Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreStateMachine::pushState Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CorePlayQueue::getTrack 0 Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::volumioPushState Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Sep 08 09:03:53 minidsp-shd volumio[1539]: info: Ignoring ROON Volume update because of undefined data Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: raat , updateDSP Sep 08 09:03:53 minidsp-shd volumio[1539]: info: updateDSP function in raat called! Sep 08 09:03:53 minidsp-shd volumio[1539]: info: Updating RAAT Signal Path Sep 08 09:03:53 minidsp-shd volumio[1539]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: raat , reconfigureAndRestartRaat Sep 08 09:03:53 minidsp-shd volumio[1539]: info: Reconfiguring and Restarting RAAT Plugin Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 08 09:03:53 minidsp-shd volumio[1539]: info: Not Reporting Auto name since its the default one Sep 08 09:03:53 minidsp-shd volumio[1539]: info: RAAT Overriding default device vendor model Sep 08 09:03:53 minidsp-shd volumio[1539]: info: Adding MINIDSP Inputs Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 08 09:03:53 minidsp-shd volumio[1539]: info: [1725811433912] CoreMusicLibrary::Adding element Inputs Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 08 09:03:53 minidsp-shd volumio[1539]: Cannot find translation for source Calm Radio Sep 08 09:03:53 minidsp-shd volumio[1539]: Cannot find translation for source YouTube2 Sep 08 09:03:53 minidsp-shd volumio[1539]: Cannot find translation for source Mother Earth Radio Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 08 09:03:53 minidsp-shd volumio[1539]: info: [1725811433919] CoreMusicLibrary::Adding element Presets Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 08 09:03:53 minidsp-shd volumio[1539]: Cannot find translation for source Calm Radio Sep 08 09:03:53 minidsp-shd volumio[1539]: Cannot find translation for source YouTube2 Sep 08 09:03:53 minidsp-shd volumio[1539]: Cannot find translation for source Mother Earth Radio Sep 08 09:03:53 minidsp-shd volumio[1539]: Cannot find translation for source Presets Sep 08 09:03:53 minidsp-shd volumio[1539]: (node:1539) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead. Sep 08 09:03:53 minidsp-shd volumio[1539]: (Use `node --trace-deprecation ...` to show where the warning was created) Sep 08 09:03:53 minidsp-shd volumio[1539]: info: Discovery: adding 923ec171-67ad-4b26-8a71-f4f034e27242 Sep 08 09:03:53 minidsp-shd volumio[1539]: info: Discovery: Found device miniDSP SHD Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CoreCommandRouter::volumioGetState Sep 08 09:03:53 minidsp-shd volumio[1539]: info: CorePlayQueue::getTrack 0 Sep 08 09:03:53 minidsp-shd go-librespot[1726]: time="2024-09-08T09:03:53-07:00" level=debug msg="obtained new client token: AABiV8TzLLBcnChCwoU9xPufbUPetqmJkot2Oe1U31/aZoxcOkEPVQi4KG7jM9jWQ1MAnBf6QKA/nxEgRLNaXYwitqEaLXlqhTKwSvyMC9NgSNBpFTIX8V6tlJJNLkGCS67G4GE3u63G57QkGfk/xNlMLCr7v+BLNxjCA61jsODaRstY2D8kS+I+todILwYzuVy/QTcw4WbidnjZmKRz86HZvl0e7p/a/KeLBekdTQlRfvYfSG6pAafefLEJs5c=" Sep 08 09:03:54 minidsp-shd volumio[1539]: info: Starting Shairport Sync Sep 08 09:03:54 minidsp-shd go-librespot[1726]: time="2024-09-08T09:03:54-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Sep 08 09:03:54 minidsp-shd volumio[1539]: info: Starting Shairport Sync Sep 08 09:03:54 minidsp-shd sudo[1751]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 08 09:03:54 minidsp-shd sudo[1751]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:03:54 minidsp-shd volumio[1539]: info: Starting Shairport Sync Sep 08 09:03:54 minidsp-shd sudo[1754]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 08 09:03:54 minidsp-shd sudo[1754]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:03:54 minidsp-shd systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 08 09:03:54 minidsp-shd systemd[1]: shairport-sync.service: Succeeded. Sep 08 09:03:54 minidsp-shd systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 08 09:03:54 minidsp-shd sudo[1757]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 08 09:03:54 minidsp-shd systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 08 09:03:54 minidsp-shd sudo[1757]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:03:54 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Sep 08 09:03:54 minidsp-shd sudo[1754]: pam_unix(sudo:session): session closed for user root Sep 08 09:03:54 minidsp-shd sudo[1751]: pam_unix(sudo:session): session closed for user root Sep 08 09:03:54 minidsp-shd systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 08 09:03:54 minidsp-shd systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Sep 08 09:03:54 minidsp-shd systemd[1]: shairport-sync.service: Succeeded. Sep 08 09:03:54 minidsp-shd systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 08 09:03:54 minidsp-shd systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 08 09:03:54 minidsp-shd sudo[1757]: pam_unix(sudo:session): session closed for user root Sep 08 09:03:54 minidsp-shd mpd[1685]: Sep 08 09:03 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 08 09:03:54 minidsp-shd systemd[1]: Started Music Player Daemon. Sep 08 09:03:54 minidsp-shd sudo[1672]: pam_unix(sudo:session): session closed for user root Sep 08 09:03:54 minidsp-shd sudo[1682]: pam_unix(sudo:session): session closed for user root Sep 08 09:03:54 minidsp-shd go-librespot[1726]: time="2024-09-08T09:03:54-07:00" level=debug msg="completed keyexchange" Sep 08 09:03:54 minidsp-shd sudo[1767]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Sep 08 09:03:54 minidsp-shd sudo[1767]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:03:54 minidsp-shd systemd[1]: Stopping RAAT DAEMON... Sep 08 09:03:54 minidsp-shd systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Sep 08 09:03:54 minidsp-shd systemd[1]: raat-daemon.service: Succeeded. Sep 08 09:03:54 minidsp-shd systemd[1]: Stopped RAAT DAEMON. Sep 08 09:03:54 minidsp-shd systemd[1]: Started RAAT DAEMON. Sep 08 09:03:54 minidsp-shd sudo[1767]: pam_unix(sudo:session): session closed for user root Sep 08 09:03:54 minidsp-shd volumio[1539]: info: Received Get System Info Sep 08 09:03:54 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 08 09:03:54 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 08 09:03:54 minidsp-shd volumio[1539]: info: Discovery: Getting this device information Sep 08 09:03:54 minidsp-shd volumio[1539]: info: CoreCommandRouter::volumioGetState Sep 08 09:03:54 minidsp-shd volumio[1539]: info: CorePlayQueue::getTrack 0 Sep 08 09:03:54 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 08 09:03:54 minidsp-shd volumio[1539]: info: CoreCommandRouter::volumioGetState Sep 08 09:03:54 minidsp-shd volumio[1539]: info: CorePlayQueue::getTrack 0 Sep 08 09:03:54 minidsp-shd volumio[1539]: Searching all installed plugins Sep 08 09:03:54 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 08 09:03:54 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: , search Sep 08 09:03:54 minidsp-shd volumio[1539]: info: CoreCommandRouter::executeOnPlugin: mpd , search Sep 08 09:03:54 minidsp-shd volumio[1539]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 08 09:03:54 minidsp-shd volumio[1539]: TypeError: Cannot read property 'then' of undefined Sep 08 09:03:54 minidsp-shd volumio[1539]: at ControllerMpd.search (/volumio/app/plugins/music_service/mpd/index.js:1582:17) Sep 08 09:03:54 minidsp-shd volumio[1539]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1077:32) Sep 08 09:03:54 minidsp-shd volumio[1539]: at CoreMusicLibrary.searchOnPlugin (/volumio/app/musiclibrary.js:668:44) Sep 08 09:03:54 minidsp-shd volumio[1539]: at CoreMusicLibrary.search (/volumio/app/musiclibrary.js:455:27) Sep 08 09:03:54 minidsp-shd volumio[1539]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:457:44) Sep 08 09:03:54 minidsp-shd volumio[1539]: at Socket.emit (events.js:400:28) Sep 08 09:03:54 minidsp-shd volumio[1539]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Sep 08 09:03:54 minidsp-shd volumio[1539]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Sep 08 09:03:54 minidsp-shd volumio[1539]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 08 09:03:54 minidsp-shd go-librespot[1726]: time="2024-09-08T09:03:54-07:00" level=debug msg="completed challenge" Sep 08 09:03:55 minidsp-shd go-librespot[1726]: time="2024-09-08T09:03:55-07:00" level=debug msg="authenticated as seyf1gokh2xqje3i089bqxgpz" Sep 08 09:03:55 minidsp-shd go-librespot[1726]: time="2024-09-08T09:03:55-07:00" level=debug msg="authenticated as seyf1gokh2xqje3i089bqxgpz" Sep 08 09:03:55 minidsp-shd go-librespot[1726]: time="2024-09-08T09:03:55-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Sep 08 09:03:55 minidsp-shd sudo[1789]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-09-08 09:02 Sep 08 09:03:55 minidsp-shd sudo[1789]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 08 09:03:55 minidsp-shd go-librespot[1726]: time="2024-09-08T09:03:55-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="17fcb754ddd6bd152b01008c46cc4ba1ca48bf35" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="281cefcd7a302aa7cfba569185cf7aae19b8c376" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="minidspshd" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 22 Mar 2024 03:00:28 PM CET" VOLUMIO_VERSION="3.608" VOLUMIO_HARDWARE="nanopineo2" VOLUMIO_DEVICENAME="NanoPi Neo2" VOLUMIO_VENDOR="miniDSP" VOLUMIO_MODEL="SHD" VOLUMIO_VENDOR_MODEL="miniDSP SHD" VOLUMIO_HASH="29ccfe8a9cff19911db4b736879ac117"