-- 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"