-- Logs begin at Fri 2024-05-03 19:17:34 UTC, end at Sat 2024-05-04 07:26:49 UTC. -- May 04 07:26:25 rivo ntpd[5649]: receive: Unexpected origin timestamp 0xe9dfb6e4.079124ab does not match aorg 0000000000.00000000 from server@129.152.16.145 xmt 0xe9e061a1.b77c712e May 04 07:26:25 rivo ntpd[5649]: receive: Unexpected origin timestamp 0xe9dfb6e4.07861ef4 does not match aorg 0000000000.00000000 from server@185.157.229.254 xmt 0xe9e061a1.b7b7cbd8 May 04 07:26:25 rivo ntpd[5649]: receive: Unexpected origin timestamp 0xe9dfb6e4.07943323 does not match aorg 0000000000.00000000 from server@95.230.240.5 xmt 0xe9e061a1.b804ea4a May 04 07:26:25 rivo systemd[1]: Starting Daily apt upgrade and clean activities... May 04 07:26:25 rivo systemd[1]: Starting Daily man-db regeneration... May 04 07:26:26 rivo systemd[1]: man-db.service: Succeeded. May 04 07:26:26 rivo systemd[1]: Started Daily man-db regeneration. May 04 07:26:26 rivo volumio[5297]: info: Loading plugin "multiroom"... May 04 07:26:27 rivo systemd[1]: apt-daily-upgrade.service: Succeeded. May 04 07:26:27 rivo systemd[1]: Started Daily apt upgrade and clean activities. May 04 07:26:28 rivo volumio[5297]: info: Applying required configuration parameters for plugin multiroom May 04 07:26:28 rivo sudo[6131]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom May 04 07:26:28 rivo sudo[6131]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:28 rivo sudo[6131]: pam_unix(sudo:session): session closed for user root May 04 07:26:28 rivo volumio[5297]: info: MRS: MultiRoom plugin initialized May 04 07:26:28 rivo volumio[5297]: info: MRS: STOPPING SNAPCLIENT May 04 07:26:28 rivo volumio[5297]: info: MRS: Snap server stop May 04 07:26:28 rivo sudo[6147]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient May 04 07:26:28 rivo volumio[5297]: info: MRS: STOPPING volumioStreaming May 04 07:26:28 rivo sudo[6147]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:28 rivo sudo[6149]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver May 04 07:26:28 rivo sudo[6149]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:28 rivo sudo[6147]: pam_unix(sudo:session): session closed for user root May 04 07:26:28 rivo sudo[6154]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming May 04 07:26:28 rivo sudo[6154]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:28 rivo volumio[5297]: info: Loading plugin "outputs"... May 04 07:26:28 rivo volumio[5297]: info: Loading plugin "albumart"... May 04 07:26:28 rivo sudo[6155]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* May 04 07:26:28 rivo sudo[6155]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:28 rivo sudo[6155]: pam_unix(sudo:session): session closed for user root May 04 07:26:28 rivo sudo[6149]: pam_unix(sudo:session): session closed for user root May 04 07:26:28 rivo sudo[6154]: pam_unix(sudo:session): session closed for user root May 04 07:26:28 rivo volumio[5297]: info: Plugin example_plugin is not enabled May 04 07:26:28 rivo volumio[5297]: info: Loading plugin "hi_res_audio"... May 04 07:26:29 rivo volumio[5297]: Forking 3 albumart workers May 04 07:26:30 rivo volumio[5297]: Starting albumart workers May 04 07:26:30 rivo volumio[5297]: Starting albumart workers May 04 07:26:30 rivo volumio[5297]: Starting albumart workers May 04 07:26:31 rivo volumio[5297]: info: Applying required configuration parameters for plugin hi_res_audio May 04 07:26:31 rivo volumio[5297]: info: Loading plugin "inputs"... May 04 07:26:32 rivo volumio[5297]: info: Loading plugin "qobuz"... May 04 07:26:34 rivo volumio[5297]: info: Loading plugin "smart_inputs"... May 04 07:26:34 rivo volumio[5297]: info: Loading plugin "tidal"... May 04 07:26:36 rivo volumio[5297]: info: Loading plugin "rivocontrol"... May 04 07:26:36 rivo systemd[1]: systemd-fsckd.service: Succeeded. May 04 07:26:36 rivo volumio[5297]: info: Adding this device properties May 04 07:26:36 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: system , setThisDeviceVolumioProperties May 04 07:26:36 rivo volumio[5297]: info: Setting Additional Device Volumio Properties: [object Object] May 04 07:26:36 rivo volumio[5297]: info: Loading plugin "updater_comm"... May 04 07:26:36 rivo volumio[5297]: info: Loading plugin "cec_controller"... May 04 07:26:37 rivo volumio[5297]: info: Applying required configuration parameters for plugin cec_controller May 04 07:26:37 rivo volumio[5297]: info: Plugin mpdemulation is not enabled May 04 07:26:37 rivo volumio[5297]: info: Loading plugin "rest_api"... May 04 07:26:37 rivo volumio[5297]: info: Loading plugin "websocket"... May 04 07:26:37 rivo volumio[5297]: info: Loading i18n strings for locale it May 04 07:26:37 rivo volumio[5297]: Updating browse sources language May 04 07:26:37 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 07:26:37 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 04 07:26:37 rivo volumio[5297]: info: CoreCommandRouter::initPlayerControls May 04 07:26:37 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:37 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:37 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:37 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:37 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:37 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:37 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:37 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:37 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 04 07:26:37 rivo volumio[5297]: Express server listening on port 3000 May 04 07:26:37 rivo volumio[5297]: [Metrics] WebUI: 26s 69.81ms May 04 07:26:37 rivo volumio[5297]: info: CoreStateMachine::resetVolumioState May 04 07:26:37 rivo volumio[5297]: info: CoreStateMachine::getcurrentVolume May 04 07:26:37 rivo volumio[5297]: info: CoreCommandRouter::volumioRetrievevolume May 04 07:26:37 rivo volumio[5297]: info: CoreStateMachine::pushState May 04 07:26:37 rivo volumio[5297]: info: CorePlayQueue::getTrack 0 May 04 07:26:37 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:26:37 rivo volumio[5297]: info: CoreCommandRouter::volumioPushState May 04 07:26:37 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 07:26:37 rivo sudo[6218]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 04 07:26:37 rivo sudo[6218]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:37 rivo sudo[6218]: pam_unix(sudo:session): session closed for user root May 04 07:26:37 rivo volumio[5297]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' May 04 07:26:37 rivo volumio[5297]: info: Completed loading Core Plugins May 04 07:26:37 rivo sudo[6221]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 04 07:26:37 rivo volumio[5297]: info: Preparing to generate the ALSA configuration file May 04 07:26:37 rivo sudo[6221]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:37 rivo sudo[6221]: pam_unix(sudo:session): session closed for user root May 04 07:26:37 rivo volumio[5297]: info: MRS: Removed streaming files May 04 07:26:37 rivo volumio[5297]: info: MRS: volumioStreaming STOPPED May 04 07:26:37 rivo volumio[5297]: info: MRS: SNAPSERVER STOPPED May 04 07:26:37 rivo volumio[5297]: info: MRS: SNAPCLIENT STOPPED May 04 07:26:37 rivo volumio[5297]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision May 04 07:26:37 rivo volumio[5297]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 04 07:26:37 rivo volumio[5297]: info: Reading ALSA contributions from plugins. May 04 07:26:38 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 04 07:26:38 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 04 07:26:38 rivo volumio[5297]: info: Discovery: Getting this device information May 04 07:26:38 rivo volumio[5297]: info: CoreCommandRouter::volumioGetState May 04 07:26:38 rivo volumio[5297]: info: CorePlayQueue::getTrack 0 May 04 07:26:38 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 04 07:26:38 rivo volumio[5297]: info: Reloading queue from file May 04 07:26:38 rivo volumio[5297]: info: CoreStateMachine::setRepeat false single undefined May 04 07:26:38 rivo volumio[5297]: info: CoreStateMachine::pushState May 04 07:26:38 rivo volumio[5297]: info: CorePlayQueue::getTrack 0 May 04 07:26:38 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:26:38 rivo volumio[5297]: info: CoreCommandRouter::volumioPushState May 04 07:26:38 rivo volumio[5297]: info: CoreStateMachine::setRandom null May 04 07:26:38 rivo volumio[5297]: info: CoreStateMachine::pushState May 04 07:26:38 rivo volumio[5297]: info: CorePlayQueue::getTrack 0 May 04 07:26:38 rivo volumio[5297]: info: CoreCommandRouter::volumioPushState May 04 07:26:38 rivo volumio[5297]: info: Discovery: A device disappeared from network May 04 07:26:38 rivo volumio[5297]: info: Discovery: Browse raised the following error TypeError: Cannot read property 'toLowerCase' of undefined May 04 07:26:38 rivo volumio[5297]: verbose: New Socket.io Connection to 192.168.1.49 from 192.168.1.57 UA: okhttp/4.9.2 Total Clients: 1 May 04 07:26:38 rivo sudo[6234]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 04 07:26:38 rivo sudo[6234]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:38 rivo volumio[5297]: info: Discovery: adding 0e9093cc-c313-4ea5-91eb-5dea1948226c May 04 07:26:38 rivo volumio[5297]: info: Discovery: Found device Rivo May 04 07:26:38 rivo volumio[5297]: info: CoreCommandRouter::volumioGetState May 04 07:26:38 rivo volumio[5297]: info: CorePlayQueue::getTrack 0 May 04 07:26:38 rivo volumio[5297]: info: MRS: Pushing multiroomSync output for this device May 04 07:26:38 rivo volumio[5297]: info: MRS: Pushing multiroomSync output May 04 07:26:38 rivo volumio[5297]: info: Adding audio output: May 04 07:26:38 rivo volumio[5297]: info: Adding audio output: May 04 07:26:38 rivo volumio[5297]: info: Asound.conf file unchanged, so no further update is needed May 04 07:26:38 rivo volumio[5297]: info: Output device has changed, restarting MPD May 04 07:26:38 rivo systemd[1]: Started UPnP Renderer front-end to MPD. May 04 07:26:38 rivo sudo[6234]: pam_unix(sudo:session): session closed for user root May 04 07:26:38 rivo volumio[5297]: info: Output device has changed, restarting Shairport Sync May 04 07:26:38 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:38 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 07:26:38 rivo sudo[6260]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 04 07:26:38 rivo sudo[6260]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:38 rivo sudo[6262]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 04 07:26:38 rivo sudo[6262]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:38 rivo sudo[6260]: pam_unix(sudo:session): session closed for user root May 04 07:26:38 rivo volumio[5297]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 04 07:26:38 rivo volumio[5297]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 04 07:26:38 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:38 rivo systemd[1]: Listening on mpd.socket. May 04 07:26:38 rivo systemd[1]: Starting Music Player Daemon... May 04 07:26:38 rivo volumio[5297]: info: ___________ START PLUGINS ___________ May 04 07:26:38 rivo volumio[5297]: info: ControllerMpd::onStart: Initializing MPD May 04 07:26:38 rivo volumio[5297]: info: Creating MPD Configuration file May 04 07:26:38 rivo kernel: aml_spdif_open May 04 07:26:38 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 May 04 07:26:38 rivo kernel: spdif_a keep clk continuous May 04 07:26:38 rivo kernel: aml_spdif_close May 04 07:26:38 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 May 04 07:26:38 rivo sudo[6284]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 04 07:26:38 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 04 07:26:38 rivo sudo[6284]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:38 rivo volumio[5297]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 04 07:26:38 rivo volumio[5297]: info: [1714807598843] CoreMusicLibrary::Adding element Server multimediali May 04 07:26:38 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 07:26:38 rivo sudo[6284]: pam_unix(sudo:session): session closed for user root May 04 07:26:38 rivo sudo[6288]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 04 07:26:38 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 04 07:26:38 rivo sudo[6288]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:38 rivo volumio[5297]: info: Adding Manifest REST API Endpoints May 04 07:26:38 rivo volumio[5297]: info: Adding manifestui REST Endpoint for plugin: miscellanea/manifestui May 04 07:26:38 rivo volumio[5297]: info: Adding METAVOLUMIO REST API Endpoints May 04 07:26:38 rivo volumio[5297]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio May 04 07:26:38 rivo volumio[5297]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio May 04 07:26:38 rivo volumio[5297]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio May 04 07:26:38 rivo volumio[5297]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio May 04 07:26:38 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:38 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 07:26:38 rivo sudo[6297]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name Rivo May 04 07:26:38 rivo sudo[6297]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:38 rivo systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM May 04 07:26:38 rivo systemd[1]: mpd.service: Succeeded. May 04 07:26:38 rivo systemd[1]: Stopped Music Player Daemon. May 04 07:26:38 rivo sudo[6297]: pam_unix(sudo:session): session closed for user root May 04 07:26:38 rivo systemd[1]: Starting Music Player Daemon... May 04 07:26:39 rivo volumio[5297]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 04 07:26:39 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:39 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 07:26:39 rivo volumio[5297]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 04 07:26:39 rivo volumio[5297]: info: Preparing CD Folders May 04 07:26:39 rivo volumio[5297]: info: Adding CD REST API Endpoints May 04 07:26:39 rivo volumio[5297]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller May 04 07:26:39 rivo volumio[5297]: info: Starting UDEV Watcher for CD May 04 07:26:39 rivo volumio[5297]: info: Detecting CD presence with UDEV May 04 07:26:39 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices May 04 07:26:39 rivo volumio[5297]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 04 07:26:39 rivo volumio[5297]: info: [1714807599137] CoreMusicLibrary::Adding element Last_100 May 04 07:26:39 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 07:26:39 rivo volumio[5297]: info: Starting RAAT Plugin May 04 07:26:39 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections May 04 07:26:39 rivo volumio[5297]: info: Additional UI Settings Added for plugin music_service/raat May 04 07:26:39 rivo volumio[5297]: info: Registering DSP Elements listener and retrieving current ones May 04 07:26:39 rivo volumio[5297]: info: Additional DSP elements updated May 04 07:26:39 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:39 rivo volumio[5297]: info: Updating RAAT Signal Path May 04 07:26:39 rivo volumio[5297]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined May 04 07:26:39 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:39 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:39 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:39 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:39 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:39 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:39 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 04 07:26:39 rivo volumio[5297]: info: Not Reporting Auto name since its the default one May 04 07:26:39 rivo volumio[5297]: info: Streaming services startup May 04 07:26:39 rivo volumio[5297]: info: Starting Streaming Daemon May 04 07:26:39 rivo sudo[6327]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 04 07:26:39 rivo sudo[6327]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:39 rivo sudo[6327]: pam_unix(sudo:session): session closed for user root May 04 07:26:39 rivo volumio[5297]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 04 07:26:39 rivo volumio[5297]: info: [1714807599386] CoreMusicLibrary::Adding element Webradio May 04 07:26:39 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 07:26:39 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 04 07:26:39 rivo sudo[6334]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 04 07:26:39 rivo sudo[6334]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:39 rivo volumio[5297]: info: Creating Spotify config file May 04 07:26:39 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:39 rivo sudo[6334]: pam_unix(sudo:session): session closed for user root May 04 07:26:39 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus May 04 07:26:39 rivo volumio[5297]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 04 07:26:39 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:39 rivo volumio[5297]: error: Hi Res Audio Failed Login: Missing Login Data May 04 07:26:39 rivo volumio[5297]: info: Adding HIGHRESAUDIO REST API Endpoints May 04 07:26:39 rivo volumio[5297]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio May 04 07:26:39 rivo volumio[5297]: info: Initializing Serial Communication on port /dev/ttyS3 May 04 07:26:39 rivo volumio[5297]: info: Touch Event Listener Process Starting May 04 07:26:39 rivo kernel: meson_uart ffd22000.serial: ttyS3 use xtal(24M) 24000000 change 0 to 9600 May 04 07:26:39 rivo kernel: meson_uart ffd22000.serial: ttyS3 use xtal(24M) 24000000 change 9600 to 9600 May 04 07:26:39 rivo kernel: meson_uart ffd22000.serial: ttyS3 use xtal(24M) 24000000 change 9600 to 115200 May 04 07:26:39 rivo kernel: aml_spdif_open May 04 07:26:39 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 May 04 07:26:39 rivo kernel: spdif_a keep clk continuous May 04 07:26:39 rivo kernel: aml_spdif_close May 04 07:26:39 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 May 04 07:26:39 rivo volumio[5297]: info: Adding inputs REST Endpoints May 04 07:26:39 rivo volumio[5297]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs May 04 07:26:39 rivo volumio[5297]: info: Scanning Audio Inputs May 04 07:26:39 rivo sudo[6342]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xinput --test-xi2 --root May 04 07:26:39 rivo sudo[6342]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:39 rivo volumio[5297]: info: Checking against Known Cards name May 04 07:26:39 rivo volumio[5297]: info: Checking against Known Cards name May 04 07:26:39 rivo volumio[5297]: info: Checking against Known Cards name May 04 07:26:39 rivo volumio[5297]: info: Checking against Known Cards name May 04 07:26:39 rivo volumio[5297]: info: Checking against Known Cards name May 04 07:26:39 rivo volumio[5297]: info: Adding Server instance for streaming May 04 07:26:39 rivo sudo[6355]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x25 0x0 May 04 07:26:39 rivo sudo[6355]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:39 rivo sudo[6355]: pam_unix(sudo:session): session closed for user root May 04 07:26:39 rivo sudo[6358]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x28 0x0 May 04 07:26:39 rivo sudo[6358]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:39 rivo sudo[6358]: pam_unix(sudo:session): session closed for user root May 04 07:26:39 rivo sudo[6361]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x29 0x1 May 04 07:26:39 rivo sudo[6361]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:39 rivo sudo[6361]: pam_unix(sudo:session): session closed for user root May 04 07:26:40 rivo sudo[6364]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x33 0x1 May 04 07:26:40 rivo sudo[6364]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:40 rivo sudo[6364]: pam_unix(sudo:session): session closed for user root May 04 07:26:40 rivo volumio[5297]: info: Apply VIM3L Onboard LEDs Settings May 04 07:26:40 rivo volumio[5297]: info: Turning On Onboard LEDs May 04 07:26:40 rivo volumio[5297]: info: Starting CEC Event listener May 04 07:26:40 rivo sudo[6368]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/sys_led/trigger May 04 07:26:40 rivo sudo[6368]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:40 rivo volumio[5297]: info: Volumio Calling Home May 04 07:26:40 rivo sudo[6368]: pam_unix(sudo:session): session closed for user root May 04 07:26:40 rivo sudo[6374]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/red_red/trigger May 04 07:26:40 rivo sudo[6374]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:40 rivo sudo[6374]: pam_unix(sudo:session): session closed for user root May 04 07:26:40 rivo volumio[5297]: (node:5297) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead. May 04 07:26:40 rivo volumio[5297]: (Use `node --trace-deprecation ...` to show where the warning was created) May 04 07:26:40 rivo volumio[5297]: info: Stopping AccessToken refresher cron for QOBUZ May 04 07:26:40 rivo volumio-remote-updater[4606]: [2024-05-04 07:26:40] [connect] Successful connection May 04 07:26:40 rivo volumio[5297]: info: AccessToken refresher cron started for QOBUZ May 04 07:26:40 rivo volumio[5297]: info: Stopping AccessToken refresher cron May 04 07:26:40 rivo volumio[5297]: info: AccessToken refresher cron started May 04 07:26:40 rivo volumio[5297]: info: Adding TIDAL REST API Endpoints May 04 07:26:40 rivo volumio[5297]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal May 04 07:26:40 rivo volumio[5297]: info: Adding QOBUZ REST API Endpoints May 04 07:26:40 rivo volumio[5297]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz May 04 07:26:40 rivo volumio[5297]: info: Serial port opened successfully May 04 07:26:40 rivo volumio[5297]: info: Sending serial start messages May 04 07:26:40 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:40 rivo volumio[5297]: info: MP1 GPIO: Signalled system ready via GPIO May 04 07:26:40 rivo volumio[5297]: info: CoreCommandRouter::volumioGetState May 04 07:26:40 rivo volumio[5297]: info: CorePlayQueue::getTrack 0 May 04 07:26:40 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 04 07:26:40 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 04 07:26:40 rivo volumio[5297]: error: Cannot start Volumio Streaming Daemon May 04 07:26:40 rivo volumio[5297]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 04 07:26:40 rivo volumio[5297]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 04 07:26:40 rivo volumio[5297]: info: RAAT Albumart path created successfully May 04 07:26:40 rivo volumio[5297]: info: Bluetooth name changed to Rivo May 04 07:26:40 rivo volumio[5297]: info: MPD Permissions set May 04 07:26:40 rivo volumio[5297]: info: MPD Permissions set May 04 07:26:40 rivo volumio[5297]: info: Upmpdcli Daemon Started May 04 07:26:40 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setDeviceVolumeOverride May 04 07:26:40 rivo volumio[5297]: info: Setting Device Volume Override May 04 07:26:40 rivo volumio[5297]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 04 07:26:41 rivo volumio[5297]: info: Updating Volume Controller Parameters: Device: 0,2 Name: S/PDIF + AES/EBU Mixer: Audio hdmi-out mute Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 04 07:26:41 rivo volumio[5297]: info: Disabling external Volume Control May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:41 rivo volumio[5297]: info: CoreStateMachine::pushState May 04 07:26:41 rivo volumio[5297]: info: CorePlayQueue::getTrack 0 May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::volumioPushState May 04 07:26:41 rivo volumio[5297]: info: MRS: Pushing multiroomSync output update for this device May 04 07:26:41 rivo volumio[5297]: info: MRS: Pushing multiroomSync output May 04 07:26:41 rivo volumio[5297]: info: CoreStateMachine::pushState May 04 07:26:41 rivo volumio[5297]: info: CorePlayQueue::getTrack 0 May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::volumioPushState May 04 07:26:41 rivo volumio[5297]: info: MRS: Pushing multiroomSync output update for this device May 04 07:26:41 rivo volumio[5297]: info: MRS: Pushing multiroomSync output May 04 07:26:41 rivo volumio-remote-updater[4606]: [2024-05-04 07:26:41] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1714807600 101 May 04 07:26:41 rivo volumio[5297]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 2 May 04 07:26:41 rivo volumio[5297]: info: Volumio called home May 04 07:26:41 rivo volumio[5297]: info: Spotify config file written May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: system , setAdditionalSVInfo May 04 07:26:41 rivo volumio[5297]: info: Setting Additional System Software info: Hardware Revision: 2.0 May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: system , setHwFwVersion May 04 07:26:41 rivo volumio[5297]: info: Setting HW Firmware info: undefined May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: system , setHwVersion May 04 07:26:41 rivo volumio[5297]: info: Setting HW Version info: 2.0 May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: system , setAdditionalSVInfo May 04 07:26:41 rivo volumio[5297]: info: Setting Additional System Software info: Hardware Revision: 2.0, Firmware Version: 0.3.3 May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: system , setHwFwVersion May 04 07:26:41 rivo volumio[5297]: info: Setting HW Firmware info: 0.3.3 May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: system , setHwVersion May 04 07:26:41 rivo volumio[5297]: info: Setting HW Version info: 2.0 May 04 07:26:41 rivo volumio[5297]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff May 04 07:26:41 rivo volumio[5297]: info: MCU Signalled Headphone Mode Disabled May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:41 rivo volumio[5297]: info: Updating RAAT Signal Path May 04 07:26:41 rivo volumio[5297]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined May 04 07:26:41 rivo volumio[5297]: info: MCU Signalled Sleep Mode Disabled May 04 07:26:41 rivo sudo[6395]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 04 07:26:41 rivo sudo[6395]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:41 rivo volumio[5297]: info: Enabling Advanced system settings configuration May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: system , addAdditionalUISections May 04 07:26:41 rivo volumio[5297]: info: Additional UI Settings Added for plugin music_service/inputs May 04 07:26:41 rivo volumio[5297]: info: MCU Signalled Auto Boot Mode On Power Disabled May 04 07:26:41 rivo volumio[5297]: info: Discovery: this is already registered, 0e9093cc-c313-4ea5-91eb-5dea1948226c May 04 07:26:41 rivo volumio[5297]: info: Discovery: Found device Rivo May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::volumioGetState May 04 07:26:41 rivo volumio[5297]: info: CorePlayQueue::getTrack 0 May 04 07:26:41 rivo sudo[6398]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms force on May 04 07:26:41 rivo sudo[6398]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:41 rivo systemd[1]: Started go-librespot Daemon. May 04 07:26:41 rivo volumio[5297]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 3 May 04 07:26:41 rivo sudo[6398]: pam_unix(sudo:session): session closed for user root May 04 07:26:41 rivo kernel: fb: osd[0] enable: 1 (Xorg) May 04 07:26:41 rivo sudo[6395]: pam_unix(sudo:session): session closed for user root May 04 07:26:41 rivo go-librespot[6401]: Librespot-go daemon starting... May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 04 07:26:41 rivo go-librespot[6401]: time="2024-05-04T07:26:41Z" level=info msg="generated new device id: 87afbb7ac0a2d4980be317c0b018d9b3537a08d7" May 04 07:26:41 rivo go-librespot[6401]: time="2024-05-04T07:26:41Z" level=debug msg="stored credentials found for lomascolo2008" May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 07:26:41 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable May 04 07:26:41 rivo volumio[5297]: error: Serial API: Failed to decode command: MAXVOL, message: 100 May 04 07:26:41 rivo sudo[6445]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service May 04 07:26:41 rivo sudo[6445]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:41 rivo sudo[6445]: pam_unix(sudo:session): session closed for user root May 04 07:26:41 rivo sudo[6448]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service May 04 07:26:41 rivo sudo[6448]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:41 rivo volumio[5297]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 4 May 04 07:26:41 rivo systemd[1]: Started RAAT DAEMON. May 04 07:26:41 rivo sudo[6448]: pam_unix(sudo:session): session closed for user root May 04 07:26:41 rivo sudo[6452]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms 0 0 0 May 04 07:26:41 rivo sudo[6452]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:41 rivo sudo[6452]: pam_unix(sudo:session): session closed for user root May 04 07:26:41 rivo kernel: aml_spdif_open May 04 07:26:41 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 May 04 07:26:41 rivo kernel: spdif_a keep clk continuous May 04 07:26:41 rivo kernel: aml_spdif_close May 04 07:26:41 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 May 04 07:26:41 rivo kernel: aml_spdif_open May 04 07:26:41 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 May 04 07:26:41 rivo kernel: spdif_a keep clk continuous May 04 07:26:41 rivo kernel: aml_spdif_close May 04 07:26:41 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 May 04 07:26:42 rivo sudo[6489]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service May 04 07:26:42 rivo sudo[6489]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:42 rivo volumio[5297]: info: Raat Daemon started successfully May 04 07:26:42 rivo volumio[5297]: info: Starting Shairport Sync May 04 07:26:42 rivo volumio[5297]: info: Starting Shairport Sync May 04 07:26:42 rivo systemd[1]: Started Volumio Bluetooth Module. May 04 07:26:42 rivo sudo[6489]: pam_unix(sudo:session): session closed for user root May 04 07:26:42 rivo volumio[5297]: info: Starting Shairport Sync May 04 07:26:42 rivo sudo[6494]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 04 07:26:42 rivo sudo[6494]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:42 rivo sudo[6508]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 04 07:26:42 rivo sudo[6508]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:42 rivo go-librespot[6401]: time="2024-05-04T07:26:42Z" level=debug msg="obtained new client token: AADraFwlyKLgPspPqxMr3k2KI0TYA6I5Cajpc2YIXS79vf3OUiPlDVVuFZdLWUDV+xljjGxD8XaK/1ru2O3ZyQI2r3FeGEwO8okJF4OngAHMrZ2qRQrcddXmB3ch7ArPoiq8i+oir8zywAkoVpTlfs5jfnKGG8HIVN8QDplwPr9sOjswZbQqBp6dPm5j3Dr4itDnkIqcnLEPmGYO2h+3y4Iaec8ra0xCBnBzsaPSpy2IanshJuCxNwMAjIQ=" May 04 07:26:42 rivo volumio[5297]: info: Adding Inputs via Serial API May 04 07:26:42 rivo volumio[5297]: info: MRS: Found cast device: TIMVISIONBOX-bf5eec2271f8d68c973ee225dc9bf9b8 May 04 07:26:42 rivo volumio[5297]: info: Adding audio output: May 04 07:26:42 rivo sudo[6511]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* May 04 07:26:42 rivo sudo[6511]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:42 rivo volumiobt[6493]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory May 04 07:26:42 rivo sudo[6511]: pam_unix(sudo:session): session closed for user root May 04 07:26:42 rivo volumio[5297]: info: CoreStateMachine::pushState May 04 07:26:42 rivo volumio[5297]: info: CorePlayQueue::getTrack 0 May 04 07:26:42 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:26:42 rivo volumio[5297]: info: CoreCommandRouter::volumioPushState May 04 07:26:42 rivo volumio[5297]: info: MRS: Pushing multiroomSync output update for this device May 04 07:26:42 rivo volumio[5297]: info: MRS: Pushing multiroomSync output May 04 07:26:42 rivo sudo[6518]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 04 07:26:42 rivo sudo[6518]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:42 rivo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 04 07:26:42 rivo systemd[1]: shairport-sync.service: Succeeded. May 04 07:26:42 rivo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 04 07:26:42 rivo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 04 07:26:42 rivo sudo[6508]: pam_unix(sudo:session): session closed for user root May 04 07:26:42 rivo sudo[6494]: pam_unix(sudo:session): session closed for user root May 04 07:26:42 rivo sudo[6518]: pam_unix(sudo:session): session closed for user root May 04 07:26:42 rivo volumio[5297]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ May 04 07:26:42 rivo volumio[5297]: SPOTIFY: BQDGHRsg4yBhLEUvM8IH3x4H4uWofn8Q19m3h_63lb0rf_chGPe8Lesh5OGm1DR1uKEdPkZ51dtpkiXi-AI4mx9CP40M_DRH2gLxyPWe93qyfPhcMhlZCURcPvy2vX7CaM1qUuQSS3NZrgC30ir8zTeytR2KOsX0aE1MVuVhCeP841Ylls2AkClODRba_NegHEjguQaMqKzS3QHrWucx0hd9kqz4ab1CG6iFSkOavvhXACP-ZR6yMiY May 04 07:26:42 rivo volumio[5297]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ May 04 07:26:42 rivo volumio[5297]: info: New Spotify access token = BQDGHRsg4yBhLEUvM8IH3x4H4uWofn8Q19m3h_63lb0rf_chGPe8Lesh5OGm1DR1uKEdPkZ51dtpkiXi-AI4mx9CP40M_DRH2gLxyPWe93qyfPhcMhlZCURcPvy2vX7CaM1qUuQSS3NZrgC30ir8zTeytR2KOsX0aE1MVuVhCeP841Ylls2AkClODRba_NegHEjguQaMqKzS3QHrWucx0hd9kqz4ab1CG6iFSkOavvhXACP-ZR6yMiY May 04 07:26:42 rivo volumio[5297]: info: Spotify credentials grant success - running version from March 24, 2019 May 04 07:26:42 rivo go-librespot[6401]: time="2024-05-04T07:26:42Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" May 04 07:26:42 rivo volumio[5297]: info: Executing endpoint restartRAATSocket May 04 07:26:42 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection May 04 07:26:42 rivo volumio[5297]: info: CoreCommandRouter::servicePushState May 04 07:26:42 rivo volumio[5297]: info: CorePlayQueue::getTrack 0 May 04 07:26:42 rivo volumio[5297]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received inputs May 04 07:26:42 rivo volumio[5297]: info: CoreCommandRouter::volumiosetSourceActiveno-source May 04 07:26:42 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 07:26:42 rivo volumio[5297]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 04 07:26:42 rivo go-librespot[6401]: time="2024-05-04T07:26:42Z" level=debug msg="completed keyexchange" May 04 07:26:42 rivo volumio[5297]: info: Shairport-Sync Started May 04 07:26:42 rivo volumio[5297]: Error adding Membership: Error: addMembership EINVAL May 04 07:26:42 rivo volumio[5297]: info: Shairport-Sync Started May 04 07:26:42 rivo volumio[5297]: info: Shairport-Sync Started May 04 07:26:42 rivo volumio[5297]: info: TidalConnect service stoped! May 04 07:26:42 rivo volumio[5297]: info: Volumio BT Module successfully started May 04 07:26:42 rivo volumio[5297]: info: CorePlayQueue::getTrack 0 May 04 07:26:42 rivo volumio[5297]: info: Turning Off Onboard LEDs May 04 07:26:42 rivo sudo[6551]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/sys_led/trigger May 04 07:26:42 rivo sudo[6551]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:43 rivo sudo[6551]: pam_unix(sudo:session): session closed for user root May 04 07:26:43 rivo mpd[6302]: May 04 07:26 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 04 07:26:43 rivo sudo[6555]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/red_red/trigger May 04 07:26:43 rivo sudo[6555]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:43 rivo volumio[5297]: info: MCU Signalled Playback Inactive May 04 07:26:43 rivo sudo[6555]: pam_unix(sudo:session): session closed for user root May 04 07:26:43 rivo systemd[1]: Started Music Player Daemon. May 04 07:26:43 rivo sudo[6262]: pam_unix(sudo:session): session closed for user root May 04 07:26:43 rivo sudo[6288]: pam_unix(sudo:session): session closed for user root May 04 07:26:43 rivo volumio[5297]: info: CoreCommandRouter::volumioGetState May 04 07:26:43 rivo volumio[5297]: info: CorePlayQueue::getTrack 0 May 04 07:26:43 rivo volumio[5297]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 5 May 04 07:26:43 rivo volumio[5297]: Upnp client error: Error: This socket has been ended by the other party May 04 07:26:43 rivo go-librespot[6401]: time="2024-05-04T07:26:43Z" level=debug msg="completed challenge" May 04 07:26:43 rivo volumio[5297]: info: CoreCommandRouter::volumioGetState May 04 07:26:43 rivo volumio[5297]: info: CorePlayQueue::getTrack 0 May 04 07:26:43 rivo go-librespot[6401]: time="2024-05-04T07:26:43Z" level=debug msg="authenticated as lomascolo2008" May 04 07:26:43 rivo volumio[5297]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 04 07:26:43 rivo volumio[5297]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect May 04 07:26:43 rivo volumio[5297]: info: Onboard LEDs initialized May 04 07:26:43 rivo sudo[6577]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio May 04 07:26:43 rivo sudo[6577]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:43 rivo sudo[6576]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 04 07:26:43 rivo sudo[6576]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:26:43 rivo volumiobt[6493]: pulseaudio: no process found May 04 07:26:43 rivo sudo[6577]: pam_unix(sudo:session): session closed for user root May 04 07:26:43 rivo systemd[1]: Started Volumio Tidal Connect Service. May 04 07:26:43 rivo sudo[6576]: pam_unix(sudo:session): session closed for user root May 04 07:26:43 rivo go-librespot[6401]: time="2024-05-04T07:26:43Z" level=debug msg="authenticated as lomascolo2008" May 04 07:26:43 rivo volumio[5297]: error: MPD error: The expression evaluated to a falsy value: May 04 07:26:43 rivo volumio[5297]: assert.ok(self.idling) May 04 07:26:43 rivo volumio[5297]: error: The expression evaluated to a falsy value: May 04 07:26:43 rivo volumio[5297]: assert.ok(self.idling) May 04 07:26:43 rivo dbus-daemon[4508]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.21' (uid=1000 pid=6605 comm="/usr/bin/pulseaudio --high-priority=true " label="kernel") May 04 07:26:43 rivo go-librespot[6401]: time="2024-05-04T07:26:43Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 04 07:26:43 rivo volumio[5297]: info: MPD running with PID6302 May 04 07:26:43 rivo volumio[5297]: ,establishing connection May 04 07:26:43 rivo volumio[5297]: error: updateQueue error: null May 04 07:26:43 rivo systemd[1]: Starting RealtimeKit Scheduling Policy Service... May 04 07:26:43 rivo go-librespot[6401]: time="2024-05-04T07:26:43Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 04 07:26:43 rivo kernel: IPVS: Creating netns size=1928 id=3 May 04 07:26:43 rivo dbus-daemon[4508]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' May 04 07:26:43 rivo systemd[1]: Started RealtimeKit Scheduling Policy Service. May 04 07:26:43 rivo rtkit-daemon[6606]: Successfully called chroot. May 04 07:26:43 rivo rtkit-daemon[6606]: Successfully dropped privileges. May 04 07:26:43 rivo rtkit-daemon[6606]: Successfully limited resources. May 04 07:26:43 rivo rtkit-daemon[6606]: Running. May 04 07:26:43 rivo rtkit-daemon[6606]: Watchdog thread running. May 04 07:26:43 rivo dbus-daemon[4508]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.22' (uid=0 pid=6606 comm="/usr/lib/rtkit/rtkit-daemon " label="kernel") May 04 07:26:43 rivo rtkit-daemon[6606]: Canary thread running. May 04 07:26:43 rivo volumio[5297]: ------------------------------------ BT MESSAGE: BT STATUS: running May 04 07:26:43 rivo systemd[1]: Starting Authorization Manager... May 04 07:26:43 rivo go-librespot[6401]: time="2024-05-04T07:26:43Z" level=debug msg="dealer connection opened" May 04 07:26:43 rivo go-librespot[6401]: time="2024-05-04T07:26:43Z" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 04 07:26:43 rivo go-librespot[6401]: time="2024-05-04T07:26:43Z" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 04 07:26:43 rivo go-librespot[6401]: time="2024-05-04T07:26:43Z" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 04 07:26:43 rivo go-librespot[6401]: time="2024-05-04T07:26:43Z" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 04 07:26:43 rivo go-librespot[6401]: time="2024-05-04T07:26:43Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513" May 04 07:26:43 rivo go-librespot[6401]: time="2024-05-04T07:26:43Z" level=debug msg="received connection id: OTFkNGZmZjYtMDk4YS00MmRiLWFjYTUtMDY1ZjY5MWQ3YjNhK2RlYWxlcit0Y3A6Ly9nZXc0LWRlYWxlci1jYW5hcnktY3N2MS5nZXc0LnNwb3RpZnkubmV0OjU3MDArQTYyNENFQUE2Q0I4OEExOUU0NDBGMzhERUFFQzVDMUI1RUNDQ0NGMzc4NDJFREU0MzMwQkY0NzhGREZCMDQ5NA==" May 04 07:26:43 rivo volumio[5297]: SPOTIFY: User informations: {"display_name":"lomascolo2008","external_urls":{"spotify":"https://open.spotify.com/user/lomascolo2008"},"href":"https://api.spotify.com/v1/users/lomascolo2008","id":"lomascolo2008","images":[],"type":"user","uri":"spotify:user:lomascolo2008","followers":{"href":null,"total":0},"country":"IT","product":"premium","explicit_content":{"filter_enabled":false,"filter_locked":false},"email":"lomascolo2008@tiscali.it"} May 04 07:26:43 rivo volumio[5297]: info: Spotify Successfully logged in May 04 07:26:43 rivo volumio[5297]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 04 07:26:43 rivo volumio[5297]: info: [1714807603907] CoreMusicLibrary::Adding element Spotify May 04 07:26:43 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 07:26:43 rivo volumio[5297]: Cannot find translation for source Spotify May 04 07:26:43 rivo polkitd[6638]: started daemon version 0.105 using authority implementation `local' version `0.105' May 04 07:26:43 rivo dbus-daemon[4508]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' May 04 07:26:43 rivo systemd[1]: Started Authorization Manager. May 04 07:26:43 rivo volumio[5297]: ------------------------------------ BT MESSAGE: BT STATUS: running May 04 07:26:44 rivo volumio[5297]: error: updateQueue error: null May 04 07:26:44 rivo go-librespot[6401]: time="2024-05-04T07:26:44Z" level=debug msg="put connect state because NEW_DEVICE" May 04 07:26:44 rivo volumio[6238]: Generating RSA private key, 4096 bit long modulus (2 primes) May 04 07:26:44 rivo volumio[5297]: info: Executing endpoint tc_getconfig May 04 07:26:44 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig May 04 07:26:44 rivo vtcs[6582]: STARTING TidalConnect services, version: 1.4.0.34 May 04 07:26:44 rivo volumio[5297]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: volumiokiosk-memorysave-touch Total Clients: 6 May 04 07:26:44 rivo vtcs[6582]: STARTED TidalConnect services. May 04 07:26:44 rivo volumio[5297]: info: Executing endpoint tc_connect May 04 07:26:44 rivo volumio[5297]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect May 04 07:26:44 rivo volumio[5297]: info: Connecting to TidalConnect May 04 07:26:44 rivo volumio[5297]: info: CoreCommandRouter::servicePushState May 04 07:26:44 rivo volumio[5297]: info: CoreStateMachine::pushState May 04 07:26:44 rivo volumio[5297]: info: CorePlayQueue::getTrack 0 May 04 07:26:44 rivo volumio[5297]: info: CoreCommandRouter::volumioPushState May 04 07:26:44 rivo volumio[5297]: info: MRS: Pushing multiroomSync output update for this device May 04 07:26:44 rivo volumio[5297]: info: MRS: Pushing multiroomSync output May 04 07:26:44 rivo volumio[5297]: info: CorePlayQueue::getTrack 0 May 04 07:26:44 rivo volumio[5297]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received tidalconnect May 04 07:26:44 rivo volumio[5297]: info: CoreCommandRouter::servicePushState May 04 07:26:44 rivo volumio[5297]: info: CoreStateMachine::pushState May 04 07:26:44 rivo volumio[5297]: info: CorePlayQueue::getTrack 0 May 04 07:26:44 rivo volumio[5297]: info: CoreCommandRouter::volumioPushState May 04 07:26:44 rivo volumio[5297]: info: MRS: Pushing multiroomSync output update for this device May 04 07:26:44 rivo volumio[5297]: info: MRS: Pushing multiroomSync output May 04 07:26:44 rivo volumio[5297]: info: CorePlayQueue::getTrack 0 May 04 07:26:44 rivo volumio[5297]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received tidalconnect May 04 07:26:44 rivo volumio[5297]: info: MRS: Getting audio outputs on start May 04 07:26:44 rivo volumio[5297]: info: MRS: Requesting all other devices output May 04 07:26:44 rivo pulseaudio[6605]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 May 04 07:26:44 rivo pulseaudio[6605]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 May 04 07:26:44 rivo pulseaudio[6605]: Failed to register as a handsfree audio agent with ofono: org.freedesktop.DBus.Error.ServiceUnknown: The name org.ofono was not provided by any .service files May 04 07:26:44 rivo bluetoothd[5724]: Endpoint registered: sender=:1.42 path=/MediaEndpoint/A2DPSource May 04 07:26:44 rivo bluetoothd[5724]: Endpoint registered: sender=:1.42 path=/MediaEndpoint/A2DPSink May 04 07:26:44 rivo volumiobt[6493]: Applying permissions May 04 07:26:44 rivo volumiobt[6493]: Setting BT discoverable and pairable May 04 07:26:44 rivo volumiobt[6493]: Agent registered May 04 07:26:44 rivo volumiobt[6493]: [bluetooth]# -e power on May 04 07:26:44 rivo volumiobt[6493]: Invalid command in menu main: -e May 04 07:26:44 rivo volumiobt[6493]: May 04 07:26:44 rivo volumiobt[6493]: Use "help" for a list of available commands in a menu. May 04 07:26:44 rivo volumiobt[6493]: Use "menu " if you want to enter any submenu. May 04 07:26:44 rivo volumiobt[6493]: Use "back" if you want to return to menu main. May 04 07:26:44 rivo volumiobt[6493]: [bluetooth]# agent on May 04 07:26:44 rivo volumiobt[6493]: Agent is already registered May 04 07:26:44 rivo volumiobt[6493]: [bluetooth]# discoverable on May 04 07:26:44 rivo volumiobt[6493]: [bluetooth]# pairable on May 04 07:26:44 rivo volumiobt[6493]: [bluetooth]# agent NoInputNoOutput May 04 07:26:44 rivo volumiobt[6493]: Agent is already registered May 04 07:26:44 rivo volumiobt[6493]: [bluetooth]# default-agent May 04 07:26:44 rivo volumiobt[6493]: [bluetooth]# quit May 04 07:26:44 rivo volumiobt[6493]: [59B blob data] May 04 07:26:44 rivo volumio[5297]: info: go-librespot daemon successfully initialized May 04 07:26:46 rivo volumio[5297]: info: TidalConnect service started! May 04 07:26:46 rivo volumio[5297]: info: Completed starting Core Plugins May 04 07:26:46 rivo volumio[5297]: info: ------------------------------------------- May 04 07:26:46 rivo volumio[5297]: info: ----- MyVolumio plugins startup ---- May 04 07:26:46 rivo volumio[5297]: info: ------------------------------------------- May 04 07:26:46 rivo volumio[5297]: info: [MyVolumio PluginManager] Fetching plans data.... May 04 07:26:46 rivo go-librespot[6401]: time="2024-05-04T07:26:46Z" level=debug msg="handling transfer player command from 87a95acd6e7e17e38cde3c55f76687f42e0b4cf3" May 04 07:26:46 rivo go-librespot[6401]: time="2024-05-04T07:26:46Z" level=trace msg="fetched new page 0 with 168 items (list: 168)" May 04 07:26:46 rivo go-librespot[6401]: time="2024-05-04T07:26:46Z" level=debug msg="loading track spotify:track:59uuKDpLFhHtCWwMudospF (paused: false, position: 121279ms)" May 04 07:26:46 rivo go-librespot[6401]: time="2024-05-04T07:26:46Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 04 07:26:46 rivo go-librespot[6401]: time="2024-05-04T07:26:46Z" level=trace msg="emitting websocket event: will_play" May 04 07:26:47 rivo go-librespot[6401]: time="2024-05-04T07:26:47Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" May 04 07:26:47 rivo go-librespot[6401]: time="2024-05-04T07:26:47Z" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:59uuKDpLFhHtCWwMudospF" May 04 07:26:47 rivo go-librespot[6401]: time="2024-05-04T07:26:47Z" level=debug msg="requested aes key for file 28514b0e8ac244b9093b85839d6b48b2eea68b51, gid: 59uuKDpLFhHtCWwMudospF" May 04 07:26:47 rivo go-librespot[6401]: time="2024-05-04T07:26:47Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1569" May 04 07:26:47 rivo go-librespot[6401]: time="2024-05-04T07:26:47Z" level=debug msg="fetched first chunk of 24, total size is 12288140 bytes" May 04 07:26:47 rivo go-librespot[6401]: time="2024-05-04T07:26:47Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1337" May 04 07:26:47 rivo go-librespot[6401]: time="2024-05-04T07:26:47Z" level=debug msg="fetched chunk 3/23, size: 524288" May 04 07:26:47 rivo go-librespot[6401]: time="2024-05-04T07:26:47Z" level=debug msg="fetched chunk 1/23, size: 524288" May 04 07:26:47 rivo go-librespot[6401]: time="2024-05-04T07:26:47Z" level=debug msg="fetched chunk 9/23, size: 524288" May 04 07:26:47 rivo go-librespot[6401]: time="2024-05-04T07:26:47Z" level=debug msg="fetched chunk 11/23, size: 524288" May 04 07:26:47 rivo volumio[5297]: info: Initializing connection to go-librespot Websocket May 04 07:26:47 rivo go-librespot[6401]: time="2024-05-04T07:26:47Z" level=debug msg="new websocket client" May 04 07:26:47 rivo go-librespot[6401]: time="2024-05-04T07:26:47Z" level=debug msg="fetched chunk 10/23, size: 524288" May 04 07:26:47 rivo go-librespot[6401]: time="2024-05-04T07:26:47Z" level=debug msg="fetched chunk 8/23, size: 524288" May 04 07:26:47 rivo go-librespot[6401]: time="2024-05-04T07:26:47Z" level=trace msg="seek to 121279ms (diff: 327ms, samples: 5348403, bytes: 4597541)" May 04 07:26:47 rivo volumio[5297]: info: Connection to go-librespot Websocket established May 04 07:26:47 rivo go-librespot[6401]: time="2024-05-04T07:26:47Z" level=debug msg="fetched chunk 2/23, size: 524288" May 04 07:26:48 rivo kernel: aml_spdif_open May 04 07:26:48 rivo go-librespot[6401]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:257:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 65536, but target_pcm volumioOutput has buffer size 32768 May 04 07:26:48 rivo go-librespot[6401]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:268:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 65536, but target_pcm volumioOutput has buffer size 32768 May 04 07:26:48 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 May 04 07:26:48 rivo kernel: set normal 512 fs /4 fs May 04 07:26:48 rivo kernel: set spdifout clk:5644800, mpll:22579200 May 04 07:26:48 rivo kernel: get spdifout clk:5644797, mpll:22579186 May 04 07:26:48 rivo kernel: aml_dai_set_spdif_fmt , fmt 0x4000 May 04 07:26:48 rivo kernel: set normal 512 fs /4 fs May 04 07:26:48 rivo kernel: set spdifout clk:5644800, mpll:22579200 May 04 07:26:48 rivo kernel: get spdifout clk:5644797, mpll:22579186 May 04 07:26:48 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 May 04 07:26:48 rivo kernel: aml_spdif_fifo_ctrl, bit depth:24, frddr type:4, toddr:type:4 May 04 07:26:48 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 May 04 07:26:48 rivo kernel: aml_spdif_fifo_ctrl, bit depth:24, frddr type:4, toddr:type:4 May 04 07:26:48 rivo go-librespot[6401]: time="2024-05-04T07:26:48Z" level=info msg="loaded track \"Goodness Of God - Live\" (uri: spotify:track:59uuKDpLFhHtCWwMudospF, paused: false, position: 121279ms, duration: 297693ms)" May 04 07:26:48 rivo go-librespot[6401]: time="2024-05-04T07:26:48Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 04 07:26:48 rivo go-librespot[6401]: time="2024-05-04T07:26:48Z" level=trace msg="emitting websocket event: metadata" May 04 07:26:48 rivo go-librespot[6401]: time="2024-05-04T07:26:48Z" level=trace msg="emitting websocket event: active" May 04 07:26:48 rivo go-librespot[6401]: time="2024-05-04T07:26:48Z" level=debug msg="sending successful reply for delaer request" May 04 07:26:48 rivo go-librespot[6401]: time="2024-05-04T07:26:48Z" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update May 04 07:26:48 rivo go-librespot[6401]: time="2024-05-04T07:26:48Z" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 04 07:26:48 rivo go-librespot[6401]: time="2024-05-04T07:26:48Z" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 04 07:26:48 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback enable May 04 07:26:48 rivo volumio[5297]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:59uuKDpLFhHtCWwMudospF","name":"Goodness Of God - Live","artist_names":["CeCe Winans"],"album_name":"Believe For It","album_cover_url":"https://i.scdn.co/image/ab67616d00001e024fb9cdf902f07d91a167c93f","position":121279,"duration":297693,"release_date":"year:2021 month:3 day:12","track_number":12,"disc_number":1}} May 04 07:26:48 rivo volumio[5297]: SPOTIFY: received: {"type":"active","data":null} May 04 07:26:48 rivo volumio[5297]: info: Aligning Spotify Volume to Volumio Volume May 04 07:26:48 rivo volumio[5297]: info: CoreCommandRouter::volumioGetState May 04 07:26:48 rivo volumio[5297]: info: CorePlayQueue::getTrack 0 May 04 07:26:48 rivo volumio[5297]: info: Setting Spotify Volume from Volumio: 100 May 04 07:26:48 rivo go-librespot[6401]: time="2024-05-04T07:26:48Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 04 07:26:48 rivo go-librespot[6401]: time="2024-05-04T07:26:48Z" level=trace msg="emitting websocket event: playing" May 04 07:26:48 rivo volumio[5297]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:59uuKDpLFhHtCWwMudospF","play_origin":"playlist"}} May 04 07:26:48 rivo volumio[5297]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 04 07:26:48 rivo volumio[5297]: TypeError: Cannot read property 'service' of undefined May 04 07:26:48 rivo volumio[5297]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:336:50) May 04 07:26:48 rivo volumio[5297]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:262:18) May 04 07:26:48 rivo volumio[5297]: at WebSocket.message (/data/plugins/music_service/spop/index.js:189:14) May 04 07:26:48 rivo volumio[5297]: at WebSocket.emit (events.js:400:28) May 04 07:26:48 rivo volumio[5297]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1203:20) May 04 07:26:48 rivo volumio[5297]: at Receiver.emit (events.js:400:28) May 04 07:26:48 rivo volumio[5297]: at /data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:608:16 May 04 07:26:48 rivo volumio[5297]: at internal/process/task_queues.js:141:7 May 04 07:26:48 rivo volumio[5297]: at AsyncResource.runInAsyncScope (async_hooks.js:197:9) May 04 07:26:48 rivo volumio[5297]: at AsyncResource.runMicrotask (internal/process/task_queues.js:138:8) May 04 07:26:48 rivo volumio[5297]: at processTicksAndRejections (internal/process/task_queues.js:95:5) May 04 07:26:48 rivo volumio[5297]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 04 07:26:48 rivo go-librespot[6401]: time="2024-05-04T07:26:48Z" level=debug msg="fetched chunk 12/23, size: 524288" May 04 07:26:48 rivo systemd[1]: systemd-hostnamed.service: Succeeded. May 04 07:26:49 rivo sudo[6737]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-05-04 07:25 May 04 07:26:49 rivo sudo[6737]: pam_unix(sudo:session): session opened for user root by (uid=0) 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="e7445fab547cd22e23d9bef72406cfb610bc1d7d" VOLUMIO_FE_VERSION="5d5e99f8f803b3ec5fc5e8ca13bb4023600f3eee" VOLUMIO_FE3_VERSION="a6ae210575eae1ff43f06ab71e1cd17576840623" VOLUMIO_BE_VERSION="a9e1e1dd6072ffb15c0fcb8938d9ea0d8900c0da" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 24 Apr 2024 02:56:04 PM CEST" VOLUMIO_VERSION="3.661" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="4aa444b01074e57a72574e89142e3734"