-- Logs begin at Tue 2024-09-24 16:50:36 CEST, end at Mon 2024-10-07 20:29:28 CEST. -- Oct 07 20:28:54 rivo ntpd[3374]: receive: Unexpected origin timestamp 0xea9d505a.e8e0facd does not match aorg 0000000000.00000000 from server@162.159.200.1 xmt 0xeaaea6e6.6049380a Oct 07 20:28:54 rivo ntpd[3374]: receive: Unexpected origin timestamp 0xea9d505a.e8dbc7e9 does not match aorg 0000000000.00000000 from server@31.14.133.122 xmt 0xeaaea6e6.611cdc45 Oct 07 20:28:54 rivo systemd[1]: Starting Daily apt download activities... Oct 07 20:28:54 rivo systemd[1]: Starting Daily man-db regeneration... Oct 07 20:28:54 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dc33000 drv_status 0x0 e_type 69 e_states 8 Oct 07 20:28:54 rivo systemd[1]: man-db.service: Succeeded. Oct 07 20:28:54 rivo systemd[1]: Started Daily man-db regeneration. Oct 07 20:28:54 rivo volumio[3386]: info: Loading plugin "upnp_browser"... Oct 07 20:28:54 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dc33000 drv_status 0x0 e_type 69 e_states 8 Oct 07 20:28:54 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dc33000 drv_status 0x0 e_type 69 e_states 8 Oct 07 20:28:54 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dc33000 drv_status 0x0 e_type 69 e_states 8 Oct 07 20:28:54 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dc33000 drv_status 0x0 e_type 69 e_states 8 Oct 07 20:28:55 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dc33000 drv_status 0x0 e_type 69 e_states 8 Oct 07 20:28:55 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dc33000 drv_status 0x0 e_type 69 e_states 8 Oct 07 20:28:55 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dc33000 drv_status 0x0 e_type 69 e_states 8 Oct 07 20:28:55 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dc33000 drv_status 0x0 e_type 69 e_states 8 Oct 07 20:28:55 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dc33000 drv_status 0x0 e_type 69 e_states 8 Oct 07 20:28:55 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dc33000 drv_status 0x0 e_type 69 e_states 8 Oct 07 20:28:55 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dc33000 drv_status 0x0 e_type 69 e_states 8 Oct 07 20:28:55 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dc33000 drv_status 0x0 e_type 69 e_states 8 Oct 07 20:28:55 rivo volumio[3386]: info: Loading plugin "bluetooth"... Oct 07 20:28:55 rivo volumio[3386]: info: [1728325735511] Starting BluetoothController Oct 07 20:28:55 rivo volumio[3386]: info: Loading plugin "alarm-clock"... Oct 07 20:28:55 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dc33000 drv_status 0x0 e_type 69 e_states 8 Oct 07 20:28:56 rivo volumio[3386]: info: Loading plugin "manifestui"... Oct 07 20:28:56 rivo systemd[1]: systemd-fsckd.service: Succeeded. Oct 07 20:28:56 rivo volumio[3386]: info: Loading plugin "metavolumio"... Oct 07 20:28:56 rivo systemd[1]: apt-daily.service: Succeeded. Oct 07 20:28:56 rivo systemd[1]: Started Daily apt download activities. Oct 07 20:28:56 rivo systemd[1]: Starting Daily apt upgrade and clean activities... Oct 07 20:28:56 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dc33000 drv_status 0x0 e_type 69 e_states 8 Oct 07 20:28:57 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dc33000 drv_status 0x0 e_type 69 e_states 8 Oct 07 20:28:57 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dc33000 drv_status 0x0 e_type 69 e_states 8 Oct 07 20:28:58 rivo kernel: CFG80211-ERROR) wl_escan_handler : escan is not ready ndev ffffffc04dc33000 drv_status 0x0 e_type 69 e_states 0 Oct 07 20:28:58 rivo volumio[3386]: info: Loading plugin "airplay_emulation"... Oct 07 20:28:58 rivo sudo[3510]: pam_unix(sudo:session): session closed for user root Oct 07 20:28:58 rivo volumio[3386]: info: Starting Shairport Sync Oct 07 20:28:58 rivo volumio[3386]: info: Loading plugin "cd_controller"... Oct 07 20:28:58 rivo volumio[3386]: info: Loading plugin "last_100"... Oct 07 20:28:58 rivo volumio[3386]: info: Loading plugin "raat"... Oct 07 20:28:58 rivo systemd[1]: apt-daily-upgrade.service: Succeeded. Oct 07 20:28:58 rivo systemd[1]: Started Daily apt upgrade and clean activities. Oct 07 20:28:59 rivo volumio[3386]: info: RAAT Plugin loaded Oct 07 20:28:59 rivo volumio[3386]: info: Adding restartRAATSocket REST API Endpoint Oct 07 20:28:59 rivo volumio[3386]: info: Adding restartRAATSocket REST Endpoint for plugin: music_service/raat Oct 07 20:28:59 rivo volumio[3386]: info: Loading plugin "streaming_services"... Oct 07 20:29:01 rivo volumio[3386]: info: Starting Streaming Service Transparent Proxy Oct 07 20:29:01 rivo volumio[3386]: info: Loading plugin "tidalconnect"... Oct 07 20:29:01 rivo volumio[3386]: info: Loading plugin "webradio"... Oct 07 20:29:02 rivo volumio[3386]: info: Loading plugin "i2s_dacs"... Oct 07 20:29:02 rivo volumio[3386]: info: I2S DAC not set, start Auto-detection Oct 07 20:29:02 rivo volumio[3386]: info: Loading plugin "volumiodiscovery"... Oct 07 20:29:02 rivo volumio[3386]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 07 20:29:02 rivo volumio[3386]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 07 20:29:02 rivo node[3386]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 07 20:29:02 rivo volumio[3386]: *** WARNING *** For more information see Oct 07 20:29:02 rivo volumio[3386]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 07 20:29:02 rivo volumio[3386]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 07 20:29:02 rivo volumio[3386]: *** WARNING *** For more information see Oct 07 20:29:02 rivo node[3386]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 07 20:29:02 rivo node[3386]: *** WARNING *** For more information see Oct 07 20:29:02 rivo node[3386]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 07 20:29:02 rivo node[3386]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 07 20:29:02 rivo node[3386]: *** WARNING *** For more information see Oct 07 20:29:02 rivo volumio[3386]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 07 20:29:02 rivo volumio[3386]: info: Discovery: Started advertising with name: Rivo Oct 07 20:29:02 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 07 20:29:02 rivo volumio[3386]: info: Loading plugin "spop"... Oct 07 20:29:03 rivo volumio[3386]: STREAMING PROXY: Starting server on port 3245 Oct 07 20:29:03 rivo volumio[3386]: Node JS runtime: 14 Oct 07 20:29:04 rivo volumio[3386]: info: Loading plugin "multiroom"... Oct 07 20:29:06 rivo volumio-remote-updater[2820]: [2024-10-07 20:29:06] [connect] Successful connection Oct 07 20:29:06 rivo volumio[3386]: info: Applying required configuration parameters for plugin multiroom Oct 07 20:29:06 rivo sudo[3798]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Oct 07 20:29:06 rivo sudo[3798]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:06 rivo sudo[3798]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:06 rivo volumio[3386]: info: MRS: MultiRoom plugin initialized Oct 07 20:29:06 rivo volumio[3386]: info: MRS: STOPPING SNAPCLIENT Oct 07 20:29:07 rivo volumio[3386]: info: MRS: Snap server stop Oct 07 20:29:07 rivo sudo[3814]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Oct 07 20:29:07 rivo sudo[3814]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:07 rivo volumio[3386]: info: MRS: STOPPING volumioStreaming Oct 07 20:29:07 rivo sudo[3816]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Oct 07 20:29:07 rivo sudo[3816]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:07 rivo volumio[3386]: info: Loading plugin "outputs"... Oct 07 20:29:07 rivo sudo[3814]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:07 rivo sudo[3819]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Oct 07 20:29:07 rivo volumio[3386]: info: Loading plugin "albumart"... Oct 07 20:29:07 rivo sudo[3819]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:07 rivo sudo[3822]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Oct 07 20:29:07 rivo sudo[3822]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:07 rivo sudo[3822]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:07 rivo sudo[3816]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:07 rivo volumio[3386]: info: Plugin example_plugin is not enabled Oct 07 20:29:07 rivo volumio[3386]: info: Loading plugin "hi_res_audio"... Oct 07 20:29:07 rivo sudo[3819]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:07 rivo volumio[3386]: Forking 3 albumart workers Oct 07 20:29:08 rivo systemd[1]: systemd-hostnamed.service: Succeeded. Oct 07 20:29:08 rivo volumio[3386]: Starting albumart workers Oct 07 20:29:08 rivo volumio[3386]: Starting albumart workers Oct 07 20:29:08 rivo volumio[3386]: Starting albumart workers Oct 07 20:29:08 rivo volumio[3386]: info: Applying required configuration parameters for plugin hi_res_audio Oct 07 20:29:08 rivo volumio[3386]: info: Loading plugin "inputs"... Oct 07 20:29:09 rivo volumio[3386]: info: Loading plugin "qobuz"... Oct 07 20:29:11 rivo volumio[3386]: info: Loading plugin "smart_inputs"... Oct 07 20:29:12 rivo volumio[3386]: info: Loading plugin "tidal"... Oct 07 20:29:12 rivo kernel: fb: mem_free_work, free memory: addr:800000 Oct 07 20:29:13 rivo volumio[3386]: info: Loading plugin "rivocontrol"... Oct 07 20:29:14 rivo volumio[3386]: info: Adding this device properties Oct 07 20:29:14 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: system , setThisDeviceVolumioProperties Oct 07 20:29:14 rivo volumio[3386]: info: Setting Additional Device Volumio Properties: [object Object] Oct 07 20:29:14 rivo volumio[3386]: info: Loading plugin "updater_comm"... Oct 07 20:29:14 rivo volumio[3386]: info: Loading plugin "cec_controller"... Oct 07 20:29:15 rivo volumio[3386]: info: Applying required configuration parameters for plugin cec_controller Oct 07 20:29:15 rivo volumio[3386]: info: Plugin mpdemulation is not enabled Oct 07 20:29:15 rivo volumio[3386]: info: Loading plugin "rest_api"... Oct 07 20:29:15 rivo volumio[3386]: info: Loading plugin "websocket"... Oct 07 20:29:15 rivo volumio[3386]: info: Starting Socket.io Server version 2.3.0 Oct 07 20:29:15 rivo volumio[3386]: info: Loading i18n strings for locale it Oct 07 20:29:15 rivo volumio[3386]: Updating browse sources language Oct 07 20:29:15 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 07 20:29:15 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 07 20:29:15 rivo volumio[3386]: info: CoreCommandRouter::initPlayerControls Oct 07 20:29:15 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:15 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:15 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:15 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:15 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:15 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:15 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:15 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:15 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 07 20:29:15 rivo volumio[3386]: Express server listening on port 3000 Oct 07 20:29:15 rivo volumio[3386]: [Metrics] WebUI: 26s 161.51ms Oct 07 20:29:15 rivo volumio[3386]: info: CoreStateMachine::resetVolumioState Oct 07 20:29:15 rivo volumio[3386]: info: CoreStateMachine::getcurrentVolume Oct 07 20:29:15 rivo volumio[3386]: info: CoreCommandRouter::volumioRetrievevolume Oct 07 20:29:15 rivo volumio[3386]: info: CoreStateMachine::pushState Oct 07 20:29:15 rivo volumio[3386]: info: CorePlayQueue::getTrack 0 Oct 07 20:29:15 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 07 20:29:15 rivo volumio[3386]: info: CoreCommandRouter::volumioPushState Oct 07 20:29:15 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 07 20:29:15 rivo sudo[3884]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 07 20:29:15 rivo sudo[3884]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:15 rivo sudo[3884]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:15 rivo volumio[3386]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Oct 07 20:29:15 rivo volumio[3386]: info: Completed loading Core Plugins Oct 07 20:29:15 rivo volumio[3386]: info: Preparing to generate the ALSA configuration file Oct 07 20:29:15 rivo sudo[3886]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 07 20:29:15 rivo sudo[3886]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:15 rivo sudo[3886]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:15 rivo volumio[3386]: info: MRS: Removed streaming files Oct 07 20:29:15 rivo volumio[3386]: info: MRS: volumioStreaming STOPPED Oct 07 20:29:15 rivo volumio[3386]: info: MRS: SNAPSERVER STOPPED Oct 07 20:29:15 rivo volumio[3386]: info: MRS: SNAPCLIENT STOPPED Oct 07 20:29:15 rivo volumio[3386]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Oct 07 20:29:15 rivo volumio[3386]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Oct 07 20:29:15 rivo volumio[3386]: info: Reading ALSA contributions from plugins. Oct 07 20:29:16 rivo volumio[3386]: info: Reloading queue from file Oct 07 20:29:16 rivo volumio[3386]: info: CoreStateMachine::setRepeat null single undefined Oct 07 20:29:16 rivo volumio[3386]: info: CoreStateMachine::pushState Oct 07 20:29:16 rivo volumio[3386]: info: CorePlayQueue::getTrack 0 Oct 07 20:29:16 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 07 20:29:16 rivo volumio[3386]: info: CoreCommandRouter::volumioPushState Oct 07 20:29:16 rivo volumio[3386]: info: CoreStateMachine::setRandom null Oct 07 20:29:16 rivo volumio[3386]: info: CoreStateMachine::pushState Oct 07 20:29:16 rivo volumio[3386]: info: CorePlayQueue::getTrack 0 Oct 07 20:29:16 rivo volumio[3386]: info: CoreCommandRouter::volumioPushState Oct 07 20:29:16 rivo volumio[3386]: info: Discovery: adding ba9a2d28-c7dd-4355-905f-53586322c162 Oct 07 20:29:16 rivo volumio[3386]: info: Discovery: Found device Rivo Oct 07 20:29:16 rivo volumio[3386]: info: CoreCommandRouter::volumioGetState Oct 07 20:29:16 rivo volumio[3386]: info: CorePlayQueue::getTrack 0 Oct 07 20:29:16 rivo sudo[3900]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 07 20:29:16 rivo volumio[3386]: info: MRS: Pushing multiroomSync output for this device Oct 07 20:29:16 rivo volumio[3386]: info: MRS: Pushing multiroomSync output Oct 07 20:29:16 rivo sudo[3900]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:16 rivo volumio[3386]: info: Adding audio output: Oct 07 20:29:16 rivo volumio[3386]: info: Adding audio output: Oct 07 20:29:16 rivo volumio[3386]: info: Asound.conf file unchanged, so no further update is needed Oct 07 20:29:16 rivo volumio[3386]: info: Output device has changed, restarting MPD Oct 07 20:29:16 rivo systemd[1]: Started UPnP Renderer front-end to MPD. Oct 07 20:29:16 rivo sudo[3900]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:16 rivo sudo[3904]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 07 20:29:16 rivo sudo[3904]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:16 rivo volumio[3386]: info: Output device has changed, restarting Shairport Sync Oct 07 20:29:16 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:16 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 07 20:29:16 rivo sudo[3904]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:16 rivo sudo[3918]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 07 20:29:16 rivo sudo[3918]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:16 rivo volumio[3386]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 07 20:29:16 rivo volumio[3386]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Oct 07 20:29:16 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:16 rivo systemd[1]: Listening on mpd.socket. Oct 07 20:29:16 rivo systemd[1]: Starting Music Player Daemon... Oct 07 20:29:16 rivo volumio[3386]: info: ___________ START PLUGINS ___________ Oct 07 20:29:16 rivo volumio[3386]: info: ControllerMpd::onStart: Initializing MPD Oct 07 20:29:16 rivo volumio[3386]: info: Creating MPD Configuration file Oct 07 20:29:16 rivo kernel: aml_spdif_open Oct 07 20:29:16 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Oct 07 20:29:16 rivo kernel: spdif_a keep clk continuous Oct 07 20:29:16 rivo kernel: aml_spdif_close Oct 07 20:29:16 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Oct 07 20:29:16 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 07 20:29:16 rivo sudo[3928]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 07 20:29:16 rivo sudo[3928]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:16 rivo volumio[3386]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 07 20:29:16 rivo volumio[3386]: info: [1728325756596] CoreMusicLibrary::Adding element Server multimediali Oct 07 20:29:16 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 07 20:29:16 rivo sudo[3928]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:16 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 07 20:29:16 rivo sudo[3932]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 07 20:29:16 rivo sudo[3932]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:16 rivo volumio[3386]: info: Adding METAVOLUMIO REST API Endpoints Oct 07 20:29:16 rivo volumio[3386]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Oct 07 20:29:16 rivo volumio[3386]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Oct 07 20:29:16 rivo volumio[3386]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Oct 07 20:29:16 rivo volumio[3386]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Oct 07 20:29:16 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:16 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 07 20:29:16 rivo systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Oct 07 20:29:16 rivo systemd[1]: mpd.service: Succeeded. Oct 07 20:29:16 rivo systemd[1]: Stopped Music Player Daemon. Oct 07 20:29:16 rivo sudo[3935]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name Rivo Oct 07 20:29:16 rivo sudo[3935]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:16 rivo systemd[1]: Starting Music Player Daemon... Oct 07 20:29:16 rivo sudo[3935]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:16 rivo volumio[3386]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 07 20:29:16 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:16 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 07 20:29:16 rivo volumio[3386]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 07 20:29:16 rivo volumio[3386]: info: Preparing CD Folders Oct 07 20:29:16 rivo volumio[3386]: info: Adding CD REST API Endpoints Oct 07 20:29:16 rivo volumio[3386]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Oct 07 20:29:16 rivo volumio[3386]: info: Starting UDEV Watcher for CD Oct 07 20:29:16 rivo volumio[3386]: info: Detecting CD presence with UDEV Oct 07 20:29:16 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Oct 07 20:29:16 rivo sudo[3938]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 07 20:29:16 rivo sudo[3938]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:16 rivo sudo[3938]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Oct 07 20:29:16 rivo sudo[3938]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:16 rivo volumio[3386]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 07 20:29:16 rivo volumio[3386]: info: [1728325756895] CoreMusicLibrary::Adding element Last_100 Oct 07 20:29:16 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 07 20:29:16 rivo volumio[3386]: info: Starting RAAT Plugin Oct 07 20:29:16 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections Oct 07 20:29:16 rivo volumio[3386]: info: Additional UI Settings Added for plugin music_service/raat Oct 07 20:29:16 rivo volumio[3386]: info: Registering DSP Elements listener and retrieving current ones Oct 07 20:29:16 rivo volumio[3386]: info: Additional DSP elements updated Oct 07 20:29:16 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:16 rivo volumio[3386]: info: Updating RAAT Signal Path Oct 07 20:29:16 rivo volumio[3386]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined Oct 07 20:29:16 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:16 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:16 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:16 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:16 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:16 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:16 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 07 20:29:16 rivo volumio[3386]: info: Not Reporting Auto name since its the default one Oct 07 20:29:17 rivo volumio[3386]: info: Streaming services startup Oct 07 20:29:17 rivo volumio[3386]: info: Starting Streaming Daemon Oct 07 20:29:17 rivo sudo[3954]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 07 20:29:17 rivo sudo[3954]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:17 rivo sudo[3954]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:17 rivo volumio[3386]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 07 20:29:17 rivo volumio[3386]: info: [1728325757132] CoreMusicLibrary::Adding element Webradio Oct 07 20:29:17 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 07 20:29:17 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 07 20:29:17 rivo volumio[3386]: info: Initializing BBC Radios Oct 07 20:29:17 rivo sudo[3961]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 07 20:29:17 rivo sudo[3961]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:17 rivo sudo[3961]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:17 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 07 20:29:17 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 07 20:29:17 rivo volumio[3386]: info: Creating Spotify config file Oct 07 20:29:17 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:17 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Oct 07 20:29:17 rivo volumio[3386]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Oct 07 20:29:17 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:17 rivo volumio[3386]: error: Hi Res Audio Failed Login: Missing Login Data Oct 07 20:29:17 rivo volumio[3386]: info: Adding HIGHRESAUDIO REST API Endpoints Oct 07 20:29:17 rivo volumio[3386]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Oct 07 20:29:17 rivo volumio[3386]: info: Initializing Serial Communication on port /dev/ttyS3 Oct 07 20:29:17 rivo volumio[3386]: info: Touch Event Listener Process Starting Oct 07 20:29:17 rivo kernel: meson_uart ffd22000.serial: ttyS3 use xtal(24M) 24000000 change 0 to 9600 Oct 07 20:29:17 rivo kernel: meson_uart ffd22000.serial: ttyS3 use xtal(24M) 24000000 change 9600 to 9600 Oct 07 20:29:17 rivo kernel: meson_uart ffd22000.serial: ttyS3 use xtal(24M) 24000000 change 9600 to 115200 Oct 07 20:29:17 rivo kernel: aml_spdif_open Oct 07 20:29:17 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Oct 07 20:29:17 rivo kernel: spdif_a keep clk continuous Oct 07 20:29:17 rivo kernel: aml_spdif_close Oct 07 20:29:17 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Oct 07 20:29:17 rivo volumio[3386]: info: Adding inputs REST Endpoints Oct 07 20:29:17 rivo volumio[3386]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Oct 07 20:29:17 rivo volumio[3386]: info: Scanning Audio Inputs Oct 07 20:29:17 rivo sudo[3979]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xinput --test-xi2 --root Oct 07 20:29:17 rivo sudo[3979]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:17 rivo volumio[3386]: info: Checking against Known Cards name Oct 07 20:29:17 rivo volumio[3386]: info: Checking against Known Cards name Oct 07 20:29:17 rivo volumio[3386]: info: Checking against Known Cards name Oct 07 20:29:17 rivo volumio[3386]: info: Checking against Known Cards name Oct 07 20:29:17 rivo volumio[3386]: info: Checking against Known Cards name Oct 07 20:29:17 rivo volumio[3386]: info: Adding Server instance for streaming Oct 07 20:29:17 rivo volumio[3386]: info: Refreshing TIDAL token Oct 07 20:29:17 rivo sudo[3990]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x25 0x0 Oct 07 20:29:17 rivo sudo[3990]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:17 rivo sudo[3990]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:17 rivo sudo[3993]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x28 0x0 Oct 07 20:29:17 rivo sudo[3993]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:17 rivo sudo[3993]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:17 rivo sudo[3996]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x29 0x1 Oct 07 20:29:18 rivo sudo[3996]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:18 rivo sudo[3996]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:18 rivo sudo[3999]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x33 0x1 Oct 07 20:29:18 rivo sudo[3999]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:18 rivo sudo[3999]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:18 rivo volumio[3386]: info: Apply VIM3L Onboard LEDs Settings Oct 07 20:29:18 rivo volumio[3386]: info: Turning On Onboard LEDs Oct 07 20:29:18 rivo sudo[4003]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/sys_led/trigger Oct 07 20:29:18 rivo sudo[4003]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:18 rivo volumio[3386]: info: Starting CEC Event listener Oct 07 20:29:18 rivo volumio[3386]: info: Volumio Calling Home Oct 07 20:29:18 rivo sudo[4003]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:18 rivo sudo[4007]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/red_red/trigger Oct 07 20:29:18 rivo sudo[4007]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:18 rivo sudo[4007]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:18 rivo volumio[3386]: (node:3386) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead. Oct 07 20:29:18 rivo volumio[3386]: (Use `node --trace-deprecation ...` to show where the warning was created) Oct 07 20:29:18 rivo volumio[3386]: info: Stopping AccessToken refresher cron for QOBUZ Oct 07 20:29:18 rivo volumio[3386]: info: AccessToken refresher cron started for QOBUZ Oct 07 20:29:18 rivo volumio[3386]: info: Adding QOBUZ REST API Endpoints Oct 07 20:29:18 rivo volumio[3386]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Oct 07 20:29:18 rivo volumio[3386]: info: Discovery: this is already registered, ba9a2d28-c7dd-4355-905f-53586322c162 Oct 07 20:29:18 rivo volumio[3386]: info: Discovery: Found device Rivo Oct 07 20:29:18 rivo volumio[3386]: info: CoreCommandRouter::volumioGetState Oct 07 20:29:18 rivo volumio[3386]: info: CorePlayQueue::getTrack 0 Oct 07 20:29:18 rivo volumio[3386]: info: Serial port opened successfully Oct 07 20:29:18 rivo volumio[3386]: info: Sending serial start messages Oct 07 20:29:18 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:18 rivo volumio[3386]: info: MP1 GPIO: Signalled system ready via GPIO Oct 07 20:29:18 rivo volumio[3386]: error: Cannot start Volumio Streaming Daemon Oct 07 20:29:18 rivo volumio[3386]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 07 20:29:18 rivo volumio[3386]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 07 20:29:18 rivo volumio[3386]: info: RAAT Albumart path created successfully Oct 07 20:29:18 rivo volumio[3386]: info: Bluetooth name changed to Rivo Oct 07 20:29:18 rivo volumio[3386]: info: MPD Permissions set Oct 07 20:29:18 rivo volumio[3386]: info: MPD Permissions set Oct 07 20:29:18 rivo volumio[3386]: info: Upmpdcli Daemon Started Oct 07 20:29:18 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setDeviceVolumeOverride Oct 07 20:29:18 rivo volumio[3386]: info: Setting Device Volume Override Oct 07 20:29:18 rivo volumio[3386]: info: CoreCommandRouter::volumioUpdateVolumeSettings Oct 07 20:29:18 rivo volumio[3386]: info: Updating Volume Controller Parameters: Device: 0,2 Name: S/PDIF + AES/EBU Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Oct 07 20:29:18 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Oct 07 20:29:18 rivo volumio[3386]: info: Disabling external Volume Control Oct 07 20:29:18 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:18 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:18 rivo volumio[3386]: info: CoreStateMachine::pushState Oct 07 20:29:18 rivo volumio[3386]: info: CorePlayQueue::getTrack 0 Oct 07 20:29:18 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 07 20:29:18 rivo volumio[3386]: info: CoreCommandRouter::volumioPushState Oct 07 20:29:18 rivo volumio[3386]: info: MRS: Pushing multiroomSync output update for this device Oct 07 20:29:18 rivo volumio[3386]: info: MRS: Pushing multiroomSync output Oct 07 20:29:18 rivo volumio[3386]: info: CoreStateMachine::pushState Oct 07 20:29:18 rivo volumio[3386]: info: CorePlayQueue::getTrack 0 Oct 07 20:29:18 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 07 20:29:18 rivo volumio[3386]: info: CoreCommandRouter::volumioPushState Oct 07 20:29:18 rivo volumio[3386]: info: MRS: Pushing multiroomSync output update for this device Oct 07 20:29:18 rivo volumio[3386]: info: MRS: Pushing multiroomSync output Oct 07 20:29:18 rivo volumio[3386]: info: Volumio called home Oct 07 20:29:18 rivo volumio[3386]: info: Spotify config file written Oct 07 20:29:18 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: system , setAdditionalSVInfo Oct 07 20:29:18 rivo volumio[3386]: info: Setting Additional System Software info: Hardware Revision: 2.0 Oct 07 20:29:18 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: system , setHwFwVersion Oct 07 20:29:18 rivo volumio[3386]: info: Setting HW Firmware info: undefined Oct 07 20:29:18 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: system , setHwVersion Oct 07 20:29:18 rivo volumio[3386]: info: Setting HW Version info: 2.0 Oct 07 20:29:18 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: system , setAdditionalSVInfo Oct 07 20:29:18 rivo volumio[3386]: info: Setting Additional System Software info: Hardware Revision: 2.0, Firmware Version: 0.3.3 Oct 07 20:29:18 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: system , setHwFwVersion Oct 07 20:29:18 rivo volumio[3386]: info: Setting HW Firmware info: 0.3.3 Oct 07 20:29:18 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: system , setHwVersion Oct 07 20:29:18 rivo volumio[3386]: info: Setting HW Version info: 2.0 Oct 07 20:29:19 rivo volumio[3386]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff Oct 07 20:29:19 rivo volumio[3386]: info: MCU Signalled Headphone Mode Disabled Oct 07 20:29:19 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Oct 07 20:29:19 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:19 rivo volumio[3386]: info: Updating RAAT Signal Path Oct 07 20:29:19 rivo volumio[3386]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined Oct 07 20:29:19 rivo volumio[3386]: info: MCU Signalled Sleep Mode Disabled Oct 07 20:29:19 rivo sudo[4026]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 07 20:29:19 rivo sudo[4026]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:19 rivo volumio[3386]: info: Enabling Advanced system settings configuration Oct 07 20:29:19 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: system , addAdditionalUISections Oct 07 20:29:19 rivo volumio[3386]: info: Additional UI Settings Added for plugin music_service/inputs Oct 07 20:29:19 rivo volumio[3386]: info: MCU Signalled Auto Boot Mode On Power Disabled Oct 07 20:29:19 rivo sudo[4032]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms force on Oct 07 20:29:19 rivo sudo[4032]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:19 rivo sudo[4032]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:19 rivo kernel: fb: osd[0] enable: 1 (Xorg) Oct 07 20:29:19 rivo systemd[1]: Started go-librespot Daemon. Oct 07 20:29:19 rivo volumio[3386]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Oct 07 20:29:19 rivo sudo[4026]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:19 rivo go-librespot[4035]: Librespot-go daemon starting... Oct 07 20:29:19 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:19 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:19 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:19 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:19 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:19 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:19 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 07 20:29:19 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 07 20:29:19 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:19 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:19 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:19 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:19 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:19 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:19 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:19 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:19 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:19 rivo go-librespot[4035]: time="2024-10-07T20:29:19+02:00" level=info msg="generated new device id: 4e3a7159034553b8400a2771afc213632d22fe56" Oct 07 20:29:19 rivo go-librespot[4035]: time="2024-10-07T20:29:19+02:00" level=debug msg="stored credentials found for 36aaxlfn4e8lhnthersxajod7" Oct 07 20:29:19 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 07 20:29:19 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 07 20:29:19 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 07 20:29:19 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Oct 07 20:29:19 rivo volumio[3386]: error: Serial API: Failed to decode command: MAXVOL, message: 100 Oct 07 20:29:19 rivo sudo[4057]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Oct 07 20:29:19 rivo sudo[4057]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:19 rivo sudo[4057]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:19 rivo sudo[4059]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Oct 07 20:29:19 rivo sudo[4059]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:19 rivo volumio[3386]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Oct 07 20:29:19 rivo systemd[1]: Started RAAT DAEMON. Oct 07 20:29:19 rivo sudo[4059]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:19 rivo kernel: aml_spdif_open Oct 07 20:29:19 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Oct 07 20:29:19 rivo kernel: spdif_a keep clk continuous Oct 07 20:29:19 rivo kernel: aml_spdif_close Oct 07 20:29:19 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Oct 07 20:29:19 rivo kernel: aml_spdif_open Oct 07 20:29:19 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Oct 07 20:29:19 rivo kernel: spdif_a keep clk continuous Oct 07 20:29:19 rivo kernel: aml_spdif_close Oct 07 20:29:19 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Oct 07 20:29:19 rivo sudo[4070]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms 0 0 0 Oct 07 20:29:19 rivo sudo[4070]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:19 rivo sudo[4076]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Oct 07 20:29:19 rivo sudo[4076]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:19 rivo sudo[4070]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:19 rivo systemd[1]: Started Volumio Bluetooth Module. Oct 07 20:29:19 rivo sudo[4076]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:19 rivo volumio[3386]: info: Raat Daemon started successfully Oct 07 20:29:20 rivo sudo[4081]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* Oct 07 20:29:20 rivo sudo[4081]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:20 rivo volumiobt[4080]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory Oct 07 20:29:20 rivo sudo[4081]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:20 rivo volumio[3386]: info: MRS: Found cast device: TIMVISIONBOX-bf5eec2271f8d68c973ee225dc9bf9b8 Oct 07 20:29:20 rivo volumio[3386]: info: Adding audio output: Oct 07 20:29:20 rivo volumio[3386]: info: MRS: Found cast device: TIMVISIONBOX-bf5eec2271f8d68c973ee225dc9bf9b8 Oct 07 20:29:20 rivo go-librespot[4035]: time="2024-10-07T20:29:20+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 07 20:29:20 rivo go-librespot[4035]: time="2024-10-07T20:29:20+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 07 20:29:20 rivo go-librespot[4035]: time="2024-10-07T20:29:20+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 07 20:29:20 rivo go-librespot[4035]: time="2024-10-07T20:29:20+02:00" level=debug msg="zeroconf server listening on port 35457" Oct 07 20:29:20 rivo volumio[3386]: info: Volumio BT Module successfully started Oct 07 20:29:20 rivo volumio[3386]: info: Starting Shairport Sync Oct 07 20:29:20 rivo volumio[3386]: info: Starting Shairport Sync Oct 07 20:29:20 rivo volumio[3386]: info: Starting Shairport Sync Oct 07 20:29:20 rivo sudo[4086]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 07 20:29:20 rivo sudo[4086]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:20 rivo go-librespot[4035]: time="2024-10-07T20:29:20+02:00" level=debug msg="obtained new client token: AAAl7ETN4KZsXgbIQDQT4tBsa/5hulm2em2R4CiFTvzKsUbvl7D8itQITOJy3HYs0lrpVMDka6a0YgbMOwPE6mHsq/beEdU0ms2ujfZNLSsBfAlAVMKWmvNJ45TNhnEgfLCS2Ba2PZVtN2Pp6khkr04mwJzX5VEyq/xHtFTSIan/bCD2ed2yof0W3Xv4cqwfyhlmCtSSWmA5vHObAohDz2XFhpRYYMFZ2lfO5JP08MOhqP7TqyhUMiL1" Oct 07 20:29:20 rivo volumio[3386]: info: Adding Inputs via Serial API Oct 07 20:29:20 rivo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 07 20:29:20 rivo sudo[4090]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 07 20:29:20 rivo systemd[1]: shairport-sync.service: Succeeded. Oct 07 20:29:20 rivo volumio[3386]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Oct 07 20:29:20 rivo volumio[3386]: SPOTIFY: BQBUw8MaLUD_PnRmBhYyz-XHGCea10ZwC_OHHrh7N18sRDtio2XVETT4ehJUxiET_BJiLTLvXgjfSDpVXvJ1zLizPPLdSv1dxBMmJWe-m3ueQ-lFUgyg6JJOudSGL7yN238PQJYbXiXynXG-8cyANNCX5KTTqfxoolyHa619e6ptQcTpC1za5SIWYO13xe_wi6XnLFPlxiyhuHnATswZ5CaPEEKGOaF9Wym2zK9fpVUzNeekx_9HpszS3pEk7C9c9_R_KbHvqmVNrt0 Oct 07 20:29:20 rivo volumio[3386]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Oct 07 20:29:20 rivo sudo[4090]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:20 rivo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 07 20:29:20 rivo volumio[3386]: info: New Spotify access token = BQBUw8MaLUD_PnRmBhYyz-XHGCea10ZwC_OHHrh7N18sRDtio2XVETT4ehJUxiET_BJiLTLvXgjfSDpVXvJ1zLizPPLdSv1dxBMmJWe-m3ueQ-lFUgyg6JJOudSGL7yN238PQJYbXiXynXG-8cyANNCX5KTTqfxoolyHa619e6ptQcTpC1za5SIWYO13xe_wi6XnLFPlxiyhuHnATswZ5CaPEEKGOaF9Wym2zK9fpVUzNeekx_9HpszS3pEk7C9c9_R_KbHvqmVNrt0 Oct 07 20:29:20 rivo volumio[3386]: info: Spotify credentials grant success - running version from March 24, 2019 Oct 07 20:29:20 rivo sudo[4091]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 07 20:29:20 rivo sudo[4091]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:20 rivo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 07 20:29:20 rivo sudo[4086]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:20 rivo volumio[3386]: info: CoreStateMachine::pushState Oct 07 20:29:20 rivo volumio[3386]: info: CorePlayQueue::getTrack 0 Oct 07 20:29:20 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 07 20:29:20 rivo volumio[3386]: info: CoreCommandRouter::volumioPushState Oct 07 20:29:20 rivo volumio[3386]: info: MRS: Pushing multiroomSync output update for this device Oct 07 20:29:20 rivo volumio[3386]: info: MRS: Pushing multiroomSync output Oct 07 20:29:20 rivo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 07 20:29:20 rivo systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Oct 07 20:29:20 rivo systemd[1]: shairport-sync.service: Succeeded. Oct 07 20:29:20 rivo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 07 20:29:20 rivo volumio[3386]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 07 20:29:20 rivo volumio[3386]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Oct 07 20:29:20 rivo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 07 20:29:20 rivo sudo[4091]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:20 rivo sudo[4090]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:20 rivo mpd[3947]: Oct 07 20:29 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 07 20:29:20 rivo volumio[3386]: info: Executing endpoint restartRAATSocket Oct 07 20:29:20 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Oct 07 20:29:20 rivo systemd[1]: Started Music Player Daemon. Oct 07 20:29:20 rivo volumio[3386]: info: CoreCommandRouter::volumioGetState Oct 07 20:29:20 rivo volumio[3386]: info: CorePlayQueue::getTrack 0 Oct 07 20:29:20 rivo sudo[3918]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:20 rivo sudo[3932]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:20 rivo volumio[3386]: info: CoreCommandRouter::servicePushState Oct 07 20:29:20 rivo volumio[3386]: info: CorePlayQueue::getTrack 0 Oct 07 20:29:20 rivo volumio[3386]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received inputs Oct 07 20:29:20 rivo volumio[3386]: info: CoreCommandRouter::volumiosetSourceActiveno-source Oct 07 20:29:20 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 07 20:29:20 rivo volumio[3386]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Oct 07 20:29:20 rivo volumio[3386]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 07 20:29:20 rivo volumio[3386]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Oct 07 20:29:20 rivo volumio[3386]: info: Access Token successfully retrieved Oct 07 20:29:20 rivo volumio[3386]: info: CoreCommandRouter::volumioGetState Oct 07 20:29:20 rivo volumio[3386]: info: CorePlayQueue::getTrack 0 Oct 07 20:29:20 rivo volumio[3386]: Upnp client error: Error: This socket has been ended by the other party Oct 07 20:29:20 rivo volumio[3386]: info: Shairport-Sync Started Oct 07 20:29:20 rivo volumio[3386]: Error adding Membership: Error: addMembership EINVAL Oct 07 20:29:20 rivo volumio[3386]: info: Shairport-Sync Started Oct 07 20:29:20 rivo volumio[3386]: info: Shairport-Sync Started Oct 07 20:29:20 rivo volumio[3386]: info: TidalConnect service stoped! Oct 07 20:29:20 rivo volumio[3386]: info: Turning Off Onboard LEDs Oct 07 20:29:20 rivo volumio[3386]: info: CorePlayQueue::getTrack 0 Oct 07 20:29:20 rivo sudo[4110]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/sys_led/trigger Oct 07 20:29:20 rivo sudo[4110]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:20 rivo sudo[4110]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:21 rivo sudo[4113]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/leds/red_red/trigger Oct 07 20:29:21 rivo sudo[4113]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:21 rivo sudo[4113]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:21 rivo sudo[4115]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio Oct 07 20:29:21 rivo sudo[4115]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:21 rivo volumio[3386]: info: MPD running with PID3947 Oct 07 20:29:21 rivo volumio[3386]: ,establishing connection Oct 07 20:29:21 rivo volumiobt[4080]: pulseaudio: no process found Oct 07 20:29:21 rivo sudo[4115]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:21 rivo go-librespot[4035]: time="2024-10-07T20:29:21+02:00" level=debug msg="completed keyexchange" Oct 07 20:29:21 rivo dbus-daemon[2818]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.22' (uid=1000 pid=4124 comm="/usr/bin/pulseaudio --high-priority=true " label="kernel") Oct 07 20:29:21 rivo volumio[3386]: error: MPD error: The expression evaluated to a falsy value: Oct 07 20:29:21 rivo volumio[3386]: assert.ok(self.idling) Oct 07 20:29:21 rivo volumio[3386]: error: The expression evaluated to a falsy value: Oct 07 20:29:21 rivo volumio[3386]: assert.ok(self.idling) Oct 07 20:29:21 rivo volumio[3386]: error: MPD error: The expression evaluated to a falsy value: Oct 07 20:29:21 rivo volumio[3386]: assert.ok(self.idling) Oct 07 20:29:21 rivo volumio[3386]: error: The expression evaluated to a falsy value: Oct 07 20:29:21 rivo volumio[3386]: assert.ok(self.idling) Oct 07 20:29:21 rivo systemd[1]: Starting RealtimeKit Scheduling Policy Service... Oct 07 20:29:21 rivo volumio[3386]: info: Onboard LEDs initialized Oct 07 20:29:21 rivo kernel: IPVS: Creating netns size=1928 id=3 Oct 07 20:29:21 rivo volumio[3386]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 07 20:29:21 rivo dbus-daemon[2818]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' Oct 07 20:29:21 rivo systemd[1]: Started RealtimeKit Scheduling Policy Service. Oct 07 20:29:21 rivo rtkit-daemon[4125]: Successfully called chroot. Oct 07 20:29:21 rivo rtkit-daemon[4125]: Successfully dropped privileges. Oct 07 20:29:21 rivo rtkit-daemon[4125]: Successfully limited resources. Oct 07 20:29:21 rivo rtkit-daemon[4125]: Running. Oct 07 20:29:21 rivo rtkit-daemon[4125]: Canary thread running. Oct 07 20:29:21 rivo rtkit-daemon[4125]: Watchdog thread running. Oct 07 20:29:21 rivo dbus-daemon[2818]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.23' (uid=0 pid=4125 comm="/usr/lib/rtkit/rtkit-daemon " label="kernel") Oct 07 20:29:21 rivo volumio[3386]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Oct 07 20:29:21 rivo volumio[3386]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Oct 07 20:29:21 rivo volumio[3386]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Oct 07 20:29:21 rivo systemd[1]: Starting Authorization Manager... Oct 07 20:29:21 rivo volumio[3386]: info: MCU Signalled Playback Inactive Oct 07 20:29:21 rivo volumio[3386]: error: updateQueue error: null Oct 07 20:29:21 rivo sudo[4130]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Oct 07 20:29:21 rivo sudo[4130]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 07 20:29:21 rivo volumio[3386]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 07 20:29:21 rivo polkitd[4129]: started daemon version 0.105 using authority implementation `local' version `0.105' Oct 07 20:29:21 rivo dbus-daemon[2818]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Oct 07 20:29:21 rivo systemd[1]: Started Authorization Manager. Oct 07 20:29:21 rivo systemd[1]: Started Volumio Tidal Connect Service. Oct 07 20:29:21 rivo sudo[4130]: pam_unix(sudo:session): session closed for user root Oct 07 20:29:21 rivo volumio-remote-updater[2820]: [2024-10-07 20:29:21] [connect] Successful connection Oct 07 20:29:21 rivo go-librespot[4035]: time="2024-10-07T20:29:21+02:00" level=debug msg="completed challenge" Oct 07 20:29:21 rivo volumio[3386]: info: Successfully retrieved User Session From TIDAL Oct 07 20:29:21 rivo go-librespot[4035]: time="2024-10-07T20:29:21+02:00" level=debug msg="authenticated as 36aaxlfn4e8lhnthersxajod7" Oct 07 20:29:21 rivo volumio[3386]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: volumiokiosk-touch Engine version: 3 Transport: polling Total Clients: 4 Oct 07 20:29:21 rivo volumio-remote-updater[2820]: [2024-10-07 20:29:21] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1728325761 101 Oct 07 20:29:21 rivo volumio[3386]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 5 Oct 07 20:29:21 rivo go-librespot[4035]: time="2024-10-07T20:29:21+02:00" level=debug msg="authenticated as 36aaxlfn4e8lhnthersxajod7" Oct 07 20:29:22 rivo volumio[3386]: SPOTIFY: User informations: {"display_name":"ilaria","external_urls":{"spotify":"https://open.spotify.com/user/36aaxlfn4e8lhnthersxajod7"},"href":"https://api.spotify.com/v1/users/36aaxlfn4e8lhnthersxajod7","id":"36aaxlfn4e8lhnthersxajod7","images":[],"type":"user","uri":"spotify:user:36aaxlfn4e8lhnthersxajod7","followers":{"href":null,"total":0},"country":"IT","product":"premium","explicit_content":{"filter_enabled":false,"filter_locked":false},"email":"ilariarenna86@gmail.com"} Oct 07 20:29:22 rivo volumio[3386]: info: Spotify Successfully logged in Oct 07 20:29:22 rivo volumio[3903]: Generating RSA private key, 4096 bit long modulus (2 primes) Oct 07 20:29:22 rivo volumio[3386]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 07 20:29:22 rivo volumio[3386]: info: [1728325762063] CoreMusicLibrary::Adding element Spotify Oct 07 20:29:22 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 07 20:29:22 rivo volumio[3386]: Cannot find translation for source Spotify Oct 07 20:29:22 rivo go-librespot[4035]: time="2024-10-07T20:29:22+02:00" level=debug msg="dealer connection opened" Oct 07 20:29:22 rivo go-librespot[4035]: time="2024-10-07T20:29:22+02:00" level=debug msg="initializing zeroconf session, username: 36aaxlfn4e8lhnthersxajod7" Oct 07 20:29:22 rivo go-librespot[4035]: time="2024-10-07T20:29:22+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Oct 07 20:29:22 rivo go-librespot[4035]: time="2024-10-07T20:29:22+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Oct 07 20:29:22 rivo go-librespot[4035]: time="2024-10-07T20:29:22+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Oct 07 20:29:22 rivo go-librespot[4035]: time="2024-10-07T20:29:22+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Oct 07 20:29:22 rivo go-librespot[4035]: time="2024-10-07T20:29:22+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 493" Oct 07 20:29:22 rivo go-librespot[4035]: time="2024-10-07T20:29:22+02:00" level=debug msg="autoplay enabled: false" Oct 07 20:29:22 rivo go-librespot[4035]: time="2024-10-07T20:29:22+02:00" level=debug msg="received connection id: NTNmY2JkODItM2UxOS00NjQ4LTlhNzctNzljNzJhZTkwYzE4K2RlYWxlcit0Y3A6Ly8wYWNhNThkOC5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArREM4MTBBODk2QkJBNDFGOUI0OUIxRTIwNEUzMTJFQkU5NDhBMkQyRUVFREYwNUQzRDNBRTA4RUE0RjY3NUI2MA==" Oct 07 20:29:22 rivo volumio[3386]: info: Successfully retrieved User Subscription From TIDAL Oct 07 20:29:22 rivo volumio[3386]: info: Adding TIDAL to Browse Sources Oct 07 20:29:22 rivo volumio[3386]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 07 20:29:22 rivo volumio[3386]: info: [1728325762173] CoreMusicLibrary::Adding element TIDAL Oct 07 20:29:22 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 07 20:29:22 rivo volumio[3386]: Cannot find translation for source Spotify Oct 07 20:29:22 rivo volumio[3386]: Cannot find translation for source TIDAL Oct 07 20:29:22 rivo volumio[3386]: info: Stopping AccessToken refresher cron Oct 07 20:29:22 rivo volumio[3386]: info: AccessToken refresher cron started Oct 07 20:29:22 rivo volumio[3386]: info: Adding TIDAL REST API Endpoints Oct 07 20:29:22 rivo volumio[3386]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Oct 07 20:29:22 rivo go-librespot[4035]: time="2024-10-07T20:29:22+02:00" level=debug msg="put connect state because NEW_DEVICE" Oct 07 20:29:22 rivo volumio[3386]: info: Executing endpoint tc_getconfig Oct 07 20:29:22 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Oct 07 20:29:22 rivo vtcs[4135]: STARTING TidalConnect services, version: 1.4.0.34 Oct 07 20:29:22 rivo pulseaudio[4124]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Oct 07 20:29:22 rivo pulseaudio[4124]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Oct 07 20:29:22 rivo volumiobt[4080]: Applying permissions Oct 07 20:29:22 rivo volumiobt[4080]: Setting BT discoverable and pairable Oct 07 20:29:22 rivo bluetoothd[3174]: Endpoint registered: sender=:1.43 path=/MediaEndpoint/A2DPSource Oct 07 20:29:22 rivo bluetoothd[3174]: Endpoint registered: sender=:1.43 path=/MediaEndpoint/A2DPSink Oct 07 20:29:22 rivo pulseaudio[4124]: 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 Oct 07 20:29:22 rivo volumio[3386]: info: MRS: Getting audio outputs on start Oct 07 20:29:22 rivo volumio[3386]: info: MRS: Requesting all other devices output Oct 07 20:29:22 rivo volumiobt[4080]: Agent registered Oct 07 20:29:22 rivo volumiobt[4080]: [bluetooth]# -e power on Oct 07 20:29:22 rivo volumiobt[4080]: Invalid command in menu main: -e Oct 07 20:29:22 rivo volumiobt[4080]: Oct 07 20:29:22 rivo volumiobt[4080]: Use "help" for a list of available commands in a menu. Oct 07 20:29:22 rivo volumiobt[4080]: Use "menu " if you want to enter any submenu. Oct 07 20:29:22 rivo volumiobt[4080]: Use "back" if you want to return to menu main. Oct 07 20:29:22 rivo volumiobt[4080]: [bluetooth]# agent on Oct 07 20:29:22 rivo volumiobt[4080]: Agent is already registered Oct 07 20:29:22 rivo volumiobt[4080]: [bluetooth]# discoverable on Oct 07 20:29:22 rivo volumiobt[4080]: [bluetooth]# pairable on Oct 07 20:29:22 rivo volumiobt[4080]: [bluetooth]# agent NoInputNoOutput Oct 07 20:29:22 rivo volumiobt[4080]: Agent is already registered Oct 07 20:29:22 rivo volumiobt[4080]: [bluetooth]# default-agent Oct 07 20:29:22 rivo volumiobt[4080]: [bluetooth]# quit Oct 07 20:29:22 rivo volumiobt[4080]: [59B blob data] Oct 07 20:29:22 rivo vtcs[4135]: STARTED TidalConnect services. Oct 07 20:29:22 rivo volumio[3386]: info: Executing endpoint tc_connect Oct 07 20:29:22 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Oct 07 20:29:22 rivo volumio[3386]: info: Connecting to TidalConnect Oct 07 20:29:22 rivo volumio[3386]: info: CoreCommandRouter::servicePushState Oct 07 20:29:22 rivo volumio[3386]: info: CoreStateMachine::pushState Oct 07 20:29:22 rivo volumio[3386]: info: CorePlayQueue::getTrack 0 Oct 07 20:29:22 rivo volumio[3386]: info: CoreCommandRouter::volumioPushState Oct 07 20:29:22 rivo volumio[3386]: info: MRS: Pushing multiroomSync output update for this device Oct 07 20:29:22 rivo volumio[3386]: info: MRS: Pushing multiroomSync output Oct 07 20:29:22 rivo volumio[3386]: info: CorePlayQueue::getTrack 0 Oct 07 20:29:22 rivo volumio[3386]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received tidalconnect Oct 07 20:29:22 rivo volumio[3386]: info: CoreCommandRouter::servicePushState Oct 07 20:29:22 rivo volumio[3386]: info: CoreStateMachine::pushState Oct 07 20:29:22 rivo volumio[3386]: info: CorePlayQueue::getTrack 0 Oct 07 20:29:22 rivo volumio[3386]: info: CoreCommandRouter::volumioPushState Oct 07 20:29:22 rivo volumio[3386]: info: MRS: Pushing multiroomSync output update for this device Oct 07 20:29:22 rivo volumio[3386]: info: MRS: Pushing multiroomSync output Oct 07 20:29:22 rivo volumio[3386]: info: CorePlayQueue::getTrack 0 Oct 07 20:29:22 rivo volumio[3386]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received tidalconnect Oct 07 20:29:22 rivo volumio[3386]: info: go-librespot daemon successfully initialized Oct 07 20:29:22 rivo volumio[3386]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 07 20:29:22 rivo volumio[3386]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Oct 07 20:29:23 rivo volumio[3386]: info: CoreCommandRouter::volumioGetState Oct 07 20:29:23 rivo volumio[3386]: info: CorePlayQueue::getTrack 0 Oct 07 20:29:24 rivo volumio[3386]: info: TidalConnect service started! Oct 07 20:29:24 rivo volumio[3386]: info: Completed starting Core Plugins Oct 07 20:29:24 rivo volumio[3386]: info: ------------------------------------------- Oct 07 20:29:24 rivo volumio[3386]: info: ----- MyVolumio plugins startup ---- Oct 07 20:29:24 rivo volumio[3386]: info: ------------------------------------------- Oct 07 20:29:24 rivo volumio[3386]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 07 20:29:24 rivo volumio[3386]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: volumiokiosk-touch Engine version: 3 Transport: polling Total Clients: 7 Oct 07 20:29:25 rivo go-librespot[4035]: time="2024-10-07T20:29:25+02:00" level=debug msg="handling transfer player command from 87a95acd6e7e17e38cde3c55f76687f42e0b4cf3" Oct 07 20:29:25 rivo go-librespot[4035]: time="2024-10-07T20:29:25+02:00" level=debug msg="resolved context of track" uri="spotify:playlist:2cfFR4JbnVsbsXeV6gBWWa" Oct 07 20:29:25 rivo go-librespot[4035]: time="2024-10-07T20:29:25+02:00" level=trace msg="fetched new page 0 with 354 items (list: 354)" uri="spotify:playlist:2cfFR4JbnVsbsXeV6gBWWa" Oct 07 20:29:25 rivo go-librespot[4035]: time="2024-10-07T20:29:25+02:00" level=debug msg="loading track (paused: false, position: 20914ms)" uri="spotify:track:3B4uJWH7xk9BSvZPaINK82" Oct 07 20:29:25 rivo volumio[3386]: info: Initializing connection to go-librespot Websocket Oct 07 20:29:25 rivo go-librespot[4035]: time="2024-10-07T20:29:25+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 07 20:29:25 rivo go-librespot[4035]: time="2024-10-07T20:29:25+02:00" level=trace msg="emitting websocket event: will_play" Oct 07 20:29:25 rivo go-librespot[4035]: time="2024-10-07T20:29:25+02:00" level=debug msg="new websocket client" Oct 07 20:29:25 rivo volumio[3386]: info: Connection to go-librespot Websocket established Oct 07 20:29:25 rivo go-librespot[4035]: time="2024-10-07T20:29:25+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Oct 07 20:29:25 rivo go-librespot[4035]: time="2024-10-07T20:29:25+02:00" level=debug msg="selected format OGG_VORBIS_320 (ee98e7354778617ce4a0267f8ee80edc1eb92a50)" uri="spotify:track:3B4uJWH7xk9BSvZPaINK82" Oct 07 20:29:25 rivo go-librespot[4035]: time="2024-10-07T20:29:25+02:00" level=debug msg="requested aes key for file ee98e7354778617ce4a0267f8ee80edc1eb92a50, gid: 3B4uJWH7xk9BSvZPaINK82" Oct 07 20:29:25 rivo go-librespot[4035]: time="2024-10-07T20:29:25+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1394" Oct 07 20:29:26 rivo volumio[3386]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Oct 07 20:29:26 rivo go-librespot[4035]: time="2024-10-07T20:29:26+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1157" Oct 07 20:29:26 rivo go-librespot[4035]: time="2024-10-07T20:29:26+02:00" level=debug msg="fetched first chunk of 17, total size is 8657992 bytes" uri="spotify:track:3B4uJWH7xk9BSvZPaINK82" Oct 07 20:29:26 rivo go-librespot[4035]: time="2024-10-07T20:29:26+02:00" level=debug msg="fetched chunk 3/16, size: 524288" uri="spotify:track:3B4uJWH7xk9BSvZPaINK82" Oct 07 20:29:26 rivo go-librespot[4035]: time="2024-10-07T20:29:26+02:00" level=debug msg="fetched chunk 1/16, size: 524288" uri="spotify:track:3B4uJWH7xk9BSvZPaINK82" Oct 07 20:29:26 rivo go-librespot[4035]: time="2024-10-07T20:29:26+02:00" level=trace msg="seek to 20914ms (diff: 192ms, samples: 922307, bytes: 796106)" uri="spotify:track:3B4uJWH7xk9BSvZPaINK82" Oct 07 20:29:26 rivo go-librespot[4035]: time="2024-10-07T20:29:26+02:00" level=debug msg="fetched chunk 4/16, size: 524288" uri="spotify:track:3B4uJWH7xk9BSvZPaINK82" Oct 07 20:29:26 rivo go-librespot[4035]: time="2024-10-07T20:29:26+02:00" level=debug msg="fetched chunk 2/16, size: 524288" uri="spotify:track:3B4uJWH7xk9BSvZPaINK82" Oct 07 20:29:26 rivo kernel: aml_spdif_open Oct 07 20:29:26 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Oct 07 20:29:26 rivo kernel: set normal 512 fs /4 fs Oct 07 20:29:26 rivo kernel: set spdifout clk:5644800, mpll:22579200 Oct 07 20:29:26 rivo kernel: get spdifout clk:5644797, mpll:22579186 Oct 07 20:29:26 rivo kernel: aml_dai_set_spdif_fmt , fmt 0x4000 Oct 07 20:29:26 rivo kernel: set normal 512 fs /4 fs Oct 07 20:29:26 rivo kernel: set spdifout clk:5644800, mpll:22579200 Oct 07 20:29:26 rivo kernel: get spdifout clk:5644797, mpll:22579186 Oct 07 20:29:26 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Oct 07 20:29:26 rivo kernel: aml_spdif_fifo_ctrl, bit depth:24, frddr type:4, toddr:type:4 Oct 07 20:29:26 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Oct 07 20:29:26 rivo kernel: aml_spdif_fifo_ctrl, bit depth:24, frddr type:4, toddr:type:4 Oct 07 20:29:26 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Oct 07 20:29:26 rivo kernel: aml_spdif_fifo_ctrl, bit depth:24, frddr type:4, toddr:type:4 Oct 07 20:29:26 rivo go-librespot[4035]: time="2024-10-07T20:29:26+02:00" level=debug msg="created new output device" Oct 07 20:29:26 rivo go-librespot[4035]: time="2024-10-07T20:29:26+02:00" level=info msg="loaded track \"(You Make Me Feel Like) A Natural Woman\" (paused: false, position: 20914ms, duration: 220893ms, prefetched: false)" uri="spotify:track:3B4uJWH7xk9BSvZPaINK82" Oct 07 20:29:26 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback enable Oct 07 20:29:26 rivo go-librespot[4035]: time="2024-10-07T20:29:26+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 07 20:29:26 rivo go-librespot[4035]: time="2024-10-07T20:29:26+02:00" level=trace msg="scheduling prefetch in 170s" Oct 07 20:29:26 rivo go-librespot[4035]: time="2024-10-07T20:29:26+02:00" level=trace msg="emitting websocket event: metadata" Oct 07 20:29:26 rivo go-librespot[4035]: time="2024-10-07T20:29:26+02:00" level=trace msg="emitting websocket event: active" Oct 07 20:29:26 rivo go-librespot[4035]: time="2024-10-07T20:29:26+02:00" level=debug msg="sending successful reply for dealer request" Oct 07 20:29:26 rivo go-librespot[4035]: time="2024-10-07T20:29:26+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Oct 07 20:29:26 rivo go-librespot[4035]: time="2024-10-07T20:29:26+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Oct 07 20:29:26 rivo go-librespot[4035]: time="2024-10-07T20:29:26+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Oct 07 20:29:26 rivo volumio[3386]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:3B4uJWH7xk9BSvZPaINK82","name":"(You Make Me Feel Like) A Natural Woman","artist_names":["Céline Dion"],"album_name":"Falling Into You","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0258c80c8f4e3e23311906f9c4","position":20914,"duration":220893,"release_date":"year:1996 month:2 day:28","track_number":8,"disc_number":1}} Oct 07 20:29:26 rivo volumio[3386]: SPOTIFY: received: {"type":"active","data":null} Oct 07 20:29:26 rivo volumio[3386]: info: Aligning Spotify Volume to Volumio Volume Oct 07 20:29:26 rivo volumio[3386]: info: CoreCommandRouter::volumioGetState Oct 07 20:29:26 rivo volumio[3386]: info: CorePlayQueue::getTrack 0 Oct 07 20:29:26 rivo volumio[3386]: info: Setting Spotify Volume from Volumio: 100 Oct 07 20:29:27 rivo go-librespot[4035]: time="2024-10-07T20:29:27+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 07 20:29:27 rivo go-librespot[4035]: time="2024-10-07T20:29:27+02:00" level=trace msg="emitting websocket event: playing" Oct 07 20:29:27 rivo volumio[3386]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:3B4uJWH7xk9BSvZPaINK82","play_origin":"playlist"}} Oct 07 20:29:27 rivo volumio[3386]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 07 20:29:27 rivo volumio[3386]: TypeError: Cannot read property 'service' of undefined Oct 07 20:29:27 rivo volumio[3386]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:336:50) Oct 07 20:29:27 rivo volumio[3386]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:262:18) Oct 07 20:29:27 rivo volumio[3386]: at WebSocket.message (/data/plugins/music_service/spop/index.js:189:14) Oct 07 20:29:27 rivo volumio[3386]: at WebSocket.emit (events.js:400:28) Oct 07 20:29:27 rivo volumio[3386]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Oct 07 20:29:27 rivo volumio[3386]: at Receiver.emit (events.js:400:28) Oct 07 20:29:27 rivo volumio[3386]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Oct 07 20:29:27 rivo volumio[3386]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Oct 07 20:29:27 rivo volumio[3386]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Oct 07 20:29:27 rivo volumio[3386]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Oct 07 20:29:27 rivo volumio[3386]: at writeOrBuffer (internal/streams/writable.js:358:12) Oct 07 20:29:27 rivo volumio[3386]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Oct 07 20:29:27 rivo volumio[3386]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Oct 07 20:29:27 rivo volumio[3386]: at Socket.emit (events.js:400:28) Oct 07 20:29:27 rivo volumio[3386]: at addChunk (internal/streams/readable.js:293:12) Oct 07 20:29:27 rivo volumio[3386]: at readableAddChunk (internal/streams/readable.js:267:9) Oct 07 20:29:27 rivo volumio[3386]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 07 20:29:28 rivo sudo[4226]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-07 20:28 Oct 07 20:29:28 rivo sudo[4226]: 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="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:47:06 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="b3e08c3e210a64867536255c2503fb09"