-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Fri 2025-05-23 16:29:04 CEST. -- May 23 16:28:00 primoultimo volumio[8228]: Starting albumart workers May 23 16:28:00 primoultimo volumio[8228]: info: Applying required configuration parameters for plugin hi_res_audio May 23 16:28:00 primoultimo volumio[8228]: info: Loading plugin "inputs"... May 23 16:28:01 primoultimo volumio-remote-updater[2853]: [2025-05-23 16:28:01] [connect] Successful connection May 23 16:28:02 primoultimo volumio[8228]: info: Loading plugin "qobuz"... May 23 16:28:04 primoultimo volumio[8228]: info: Loading plugin "smart_inputs"... May 23 16:28:04 primoultimo volumio[8228]: info: Loading plugin "tidal"... May 23 16:28:07 primoultimo volumio[8228]: info: Loading plugin "primo2rev2control"... May 23 16:28:07 primoultimo volumio[8228]: info: Adding this device properties May 23 16:28:07 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , setThisDeviceVolumioProperties May 23 16:28:07 primoultimo volumio[8228]: info: Setting Additional Device Volumio Properties: [object Object] May 23 16:28:07 primoultimo volumio[8228]: info: Loading plugin "updater_comm"... May 23 16:28:07 primoultimo volumio[8228]: info: Loading plugin "cec_controller"... May 23 16:28:08 primoultimo volumio[8228]: info: Applying required configuration parameters for plugin cec_controller May 23 16:28:08 primoultimo volumio[8228]: info: Plugin mpdemulation is not enabled May 23 16:28:08 primoultimo volumio[8228]: info: Loading plugin "rest_api"... May 23 16:28:08 primoultimo volumio[8228]: info: Loading plugin "websocket"... May 23 16:28:08 primoultimo volumio[8228]: info: Starting Socket.io Server version 2.3.0 May 23 16:28:08 primoultimo volumio[8228]: info: Loading plugin "fusiondsp"... May 23 16:28:08 primoultimo volumio[8228]: info: Applying required configuration parameters for plugin fusiondsp May 23 16:28:08 primoultimo volumio[8228]: info: Loading plugin "backup_restore"... May 23 16:28:09 primoultimo volumio[8228]: info: Applying required configuration parameters for plugin backup_restore May 23 16:28:09 primoultimo volumio[8228]: info: Loading i18n strings for locale it May 23 16:28:09 primoultimo volumio[8228]: Updating browse sources language May 23 16:28:09 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 23 16:28:09 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 23 16:28:09 primoultimo volumio[8228]: info: CoreCommandRouter::initPlayerControls May 23 16:28:09 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:09 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:09 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:09 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:09 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:09 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:09 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 23 16:28:09 primoultimo volumio[8228]: Express server listening on port 3000 May 23 16:28:09 primoultimo volumio[8228]: [Metrics] WebUI: 37s 867.87ms May 23 16:28:09 primoultimo volumio[8228]: info: CoreStateMachine::resetVolumioState May 23 16:28:09 primoultimo volumio[8228]: info: CoreStateMachine::getcurrentVolume May 23 16:28:09 primoultimo volumio[8228]: info: CoreCommandRouter::volumioRetrievevolume May 23 16:28:09 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 16:28:10 primoultimo sudo[8459]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 23 16:28:10 primoultimo sudo[8459]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:10 primoultimo volumio[8228]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' May 23 16:28:10 primoultimo volumio[8228]: info: Completed loading Core Plugins May 23 16:28:10 primoultimo volumio[8228]: info: Preparing to generate the ALSA configuration file May 23 16:28:10 primoultimo sudo[8461]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 23 16:28:10 primoultimo sudo[8461]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:10 primoultimo sudo[8459]: pam_unix(sudo:session): session closed for user root May 23 16:28:10 primoultimo sudo[8461]: pam_unix(sudo:session): session closed for user root May 23 16:28:10 primoultimo volumio[8228]: info: Volumio Network Manager: Network status updated: 1 May 23 16:28:10 primoultimo volumio[8228]: Unable to parse: May 23 16:28:10 primoultimo volumio[8228]: Simple mixer control 'Audio hdmi-out mute',0 May 23 16:28:10 primoultimo volumio[8228]: Capabilities: pswitch pswitch-joined May 23 16:28:10 primoultimo volumio[8228]: Playback channels: Mono May 23 16:28:10 primoultimo volumio[8228]: Mono: Playback [on] May 23 16:28:10 primoultimo volumio[8228]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output May 23 16:28:10 primoultimo volumio[8228]: info: MRS: Removed streaming files May 23 16:28:10 primoultimo volumio[8228]: info: MRS: volumioStreaming STOPPED May 23 16:28:10 primoultimo volumio[8228]: info: MRS: SNAPSERVER STOPPED May 23 16:28:10 primoultimo volumio[8228]: info: MRS: SNAPCLIENT STOPPED May 23 16:28:10 primoultimo volumio[8228]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision May 23 16:28:10 primoultimo volumio[8228]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 23 16:28:10 primoultimo volumio[8228]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 23 16:28:10 primoultimo volumio[8228]: info: Reading ALSA contributions from plugins. May 23 16:28:10 primoultimo volumio[8228]: 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: 1 May 23 16:28:10 primoultimo volumio[8228]: 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: 2 May 23 16:28:10 primoultimo volumio[8228]: 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: 3 May 23 16:28:10 primoultimo volumio[8228]: 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 May 23 16:28:10 primoultimo volumio[8228]: 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: 5 May 23 16:28:10 primoultimo volumio[8228]: 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: 6 May 23 16:28:10 primoultimo volumio[8228]: 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 May 23 16:28:10 primoultimo volumio[8228]: Unable to parse: May 23 16:28:10 primoultimo volumio[8228]: Simple mixer control 'Audio hdmi-out mute',0 May 23 16:28:10 primoultimo volumio[8228]: Capabilities: pswitch pswitch-joined May 23 16:28:10 primoultimo volumio[8228]: Playback channels: Mono May 23 16:28:10 primoultimo volumio[8228]: Mono: Playback [on] May 23 16:28:10 primoultimo volumio[8228]: info: VolumeController:: Volume=undefined Mute =false May 23 16:28:10 primoultimo volumio[8228]: info: CoreStateMachine::pushState May 23 16:28:10 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:10 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 23 16:28:10 primoultimo volumio[8228]: info: CoreCommandRouter::volumioPushState May 23 16:28:10 primoultimo volumio[8228]: info: CoreStateMachine::updateTrackBlock May 23 16:28:10 primoultimo volumio[8228]: info: CorePlayQueue::getTrackBlock May 23 16:28:10 primoultimo volumio[8228]: info: CoreCommandRouter::volumioRetrievevolume May 23 16:28:10 primoultimo volumio[8228]: info: Reloading queue from file May 23 16:28:10 primoultimo volumio[8228]: info: CoreStateMachine::setRepeat null single undefined May 23 16:28:10 primoultimo volumio[8228]: info: CoreStateMachine::pushState May 23 16:28:10 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:10 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 23 16:28:10 primoultimo volumio[8228]: info: CoreCommandRouter::volumioPushState May 23 16:28:10 primoultimo volumio[8228]: info: CoreStateMachine::setRandom null May 23 16:28:10 primoultimo volumio[8228]: info: CoreStateMachine::pushState May 23 16:28:10 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:10 primoultimo volumio[8228]: info: CoreCommandRouter::volumioPushState May 23 16:28:10 primoultimo volumio[8228]: Unable to parse: May 23 16:28:10 primoultimo volumio[8228]: Simple mixer control 'Audio hdmi-out mute',0 May 23 16:28:10 primoultimo volumio[8228]: Capabilities: pswitch pswitch-joined May 23 16:28:10 primoultimo volumio[8228]: Playback channels: Mono May 23 16:28:10 primoultimo volumio[8228]: Mono: Playback [on] May 23 16:28:10 primoultimo volumio[8228]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output May 23 16:28:11 primoultimo volumio[8228]: Unable to parse: May 23 16:28:11 primoultimo volumio[8228]: Simple mixer control 'Audio hdmi-out mute',0 May 23 16:28:11 primoultimo volumio[8228]: Capabilities: pswitch pswitch-joined May 23 16:28:11 primoultimo volumio[8228]: Playback channels: Mono May 23 16:28:11 primoultimo volumio[8228]: Mono: Playback [on] May 23 16:28:11 primoultimo volumio[8228]: info: VolumeController:: Volume=undefined Mute =false May 23 16:28:11 primoultimo volumio[8228]: info: CoreStateMachine::pushState May 23 16:28:11 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:11 primoultimo volumio[8228]: info: CoreCommandRouter::volumioPushState May 23 16:28:11 primoultimo volumio[8228]: info: Discovery: adding 540bd688-ac25-4bf9-bd70-55f65b3738d6 May 23 16:28:11 primoultimo volumio[8228]: info: Discovery: Found device Primo&ultimo May 23 16:28:11 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:11 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:11 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output for this device May 23 16:28:11 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output May 23 16:28:11 primoultimo volumio[8228]: info: Adding audio output: May 23 16:28:11 primoultimo sudo[8478]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 23 16:28:11 primoultimo volumio[8228]: info: Adding audio output: May 23 16:28:11 primoultimo sudo[8478]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:11 primoultimo volumio[8228]: info: Asound.conf file unchanged, so no further update is needed May 23 16:28:11 primoultimo volumio[8228]: info: Output device has changed, restarting MPD May 23 16:28:11 primoultimo sudo[8478]: pam_unix(sudo:session): session closed for user root May 23 16:28:11 primoultimo volumio[8228]: info: Output device has changed, restarting Shairport Sync May 23 16:28:11 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:11 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 16:28:11 primoultimo sudo[8481]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 23 16:28:11 primoultimo sudo[8481]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:11 primoultimo sudo[8481]: pam_unix(sudo:session): session closed for user root May 23 16:28:11 primoultimo sudo[8483]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 23 16:28:11 primoultimo sudo[8483]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:11 primoultimo systemd[1]: Stopping Music Player Daemon... May 23 16:28:11 primoultimo volumio[8228]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 23 16:28:11 primoultimo volumio[8228]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 23 16:28:11 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:11 primoultimo systemd[1]: mpd.service: Succeeded. May 23 16:28:11 primoultimo systemd[1]: Stopped Music Player Daemon. May 23 16:28:11 primoultimo systemd[1]: Starting Music Player Daemon... May 23 16:28:11 primoultimo volumio[8228]: info: ___________ START PLUGINS ___________ May 23 16:28:11 primoultimo volumio[8228]: info: ControllerMpd::onStart: Initializing MPD May 23 16:28:11 primoultimo volumio[8228]: info: Creating MPD Configuration file May 23 16:28:11 primoultimo kernel: aml_tdm_open May 23 16:28:11 primoultimo kernel: Not init audio effects May 23 16:28:11 primoultimo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:tdm@1 May 23 16:28:11 primoultimo kernel: tdm playback mute: 1, lane_cnt = 8 May 23 16:28:11 primoultimo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:tdm@1 May 23 16:28:11 primoultimo sudo[8500]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 23 16:28:11 primoultimo sudo[8500]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:11 primoultimo sudo[8500]: pam_unix(sudo:session): session closed for user root May 23 16:28:11 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 23 16:28:11 primoultimo volumio[8228]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 23 16:28:11 primoultimo volumio[8228]: info: [1748010491627] CoreMusicLibrary::Adding element Server multimediali May 23 16:28:11 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 23 16:28:11 primoultimo sudo[8491]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 23 16:28:11 primoultimo sudo[8491]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:11 primoultimo sudo[8491]: pam_unix(sudo:session): session closed for user root May 23 16:28:11 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 23 16:28:11 primoultimo sudo[8503]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 23 16:28:11 primoultimo sudo[8503]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:11 primoultimo volumio[8228]: info: Adding METAVOLUMIO REST API Endpoints May 23 16:28:11 primoultimo volumio[8228]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio May 23 16:28:11 primoultimo volumio[8228]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio May 23 16:28:11 primoultimo volumio[8228]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio May 23 16:28:11 primoultimo volumio[8228]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio May 23 16:28:11 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:11 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 16:28:11 primoultimo systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM May 23 16:28:11 primoultimo systemd[1]: mpd.service: Succeeded. May 23 16:28:11 primoultimo systemd[1]: Stopped Music Player Daemon. May 23 16:28:11 primoultimo systemd[1]: Starting Music Player Daemon... May 23 16:28:11 primoultimo sudo[8512]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name Primo&ultimo May 23 16:28:11 primoultimo sudo[8512]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:11 primoultimo sudo[8512]: pam_unix(sudo:session): session closed for user root May 23 16:28:11 primoultimo volumio[8228]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 23 16:28:11 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:11 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 16:28:12 primoultimo sudo[8518]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 23 16:28:12 primoultimo sudo[8518]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:12 primoultimo sudo[8518]: pam_unix(sudo:session): session closed for user root May 23 16:28:12 primoultimo volumio[8228]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 23 16:28:12 primoultimo volumio[8228]: info: Preparing CD Folders May 23 16:28:12 primoultimo volumio[8228]: info: Adding CD REST API Endpoints May 23 16:28:12 primoultimo volumio[8228]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller May 23 16:28:12 primoultimo volumio[8228]: info: Starting UDEV Watcher for CD May 23 16:28:12 primoultimo volumio[8228]: info: Detecting CD presence with UDEV May 23 16:28:12 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices May 23 16:28:12 primoultimo volumio[8228]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 23 16:28:12 primoultimo volumio[8228]: info: [1748010492149] CoreMusicLibrary::Adding element Last_100 May 23 16:28:12 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 23 16:28:12 primoultimo volumio[8228]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect May 23 16:28:12 primoultimo volumio[8228]: info: QobuzConnect: Starting Qobuz Connect socket and service May 23 16:28:12 primoultimo volumio[8228]: info: Starting RAAT Plugin May 23 16:28:12 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections May 23 16:28:12 primoultimo volumio[8228]: info: Additional UI Settings Added for plugin music_service/raat May 23 16:28:12 primoultimo volumio[8228]: info: Registering DSP Elements listener and retrieving current ones May 23 16:28:12 primoultimo volumio[8228]: info: Additional DSP elements updated May 23 16:28:12 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:12 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:12 primoultimo volumio[8228]: info: Updating RAAT Signal Path May 23 16:28:12 primoultimo volumio[8228]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined May 23 16:28:12 primoultimo volumio[8228]: info: Streaming services startup May 23 16:28:12 primoultimo volumio[8228]: info: Starting Streaming Daemon May 23 16:28:12 primoultimo sudo[8569]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 23 16:28:12 primoultimo sudo[8569]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:12 primoultimo sudo[8569]: pam_unix(sudo:session): session closed for user root May 23 16:28:12 primoultimo sudo[8572]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 23 16:28:12 primoultimo sudo[8572]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:12 primoultimo sudo[8573]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 23 16:28:12 primoultimo sudo[8573]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:12 primoultimo sudo[8572]: pam_unix(sudo:session): session closed for user root May 23 16:28:12 primoultimo systemd[1]: Stopping Volumio Qobuz Connect Service... May 23 16:28:12 primoultimo qobuz-connect[4414]: 20250523 16:28:12.619 [4414.4414] INFO SampleApp: Stopping Local configuration server May 23 16:28:12 primoultimo volumio[8228]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 23 16:28:12 primoultimo volumio[8228]: info: [1748010492694] CoreMusicLibrary::Adding element Webradio May 23 16:28:12 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 23 16:28:12 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 23 16:28:12 primoultimo volumio[8228]: info: Initializing BBC Radios May 23 16:28:12 primoultimo sudo[8583]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 23 16:28:12 primoultimo sudo[8583]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:12 primoultimo systemd[1]: qobuz-connect.service: Succeeded. May 23 16:28:12 primoultimo systemd[1]: Stopped Volumio Qobuz Connect Service. May 23 16:28:12 primoultimo systemd[1]: Started Volumio Qobuz Connect Service. May 23 16:28:12 primoultimo sudo[8573]: pam_unix(sudo:session): session closed for user root May 23 16:28:12 primoultimo systemd[1]: Stopping Volumio Tidal Connect Service... May 23 16:28:12 primoultimo systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM May 23 16:28:12 primoultimo systemd[1]: vtcs.service: Succeeded. May 23 16:28:12 primoultimo systemd[1]: Stopped Volumio Tidal Connect Service. May 23 16:28:12 primoultimo sudo[8583]: pam_unix(sudo:session): session closed for user root May 23 16:28:12 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 23 16:28:12 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 16:28:13 primoultimo volumio[8228]: info: Creating Spotify config file May 23 16:28:13 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:13 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus May 23 16:28:13 primoultimo volumio[8228]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 23 16:28:13 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:13 primoultimo volumio[8228]: error: Hi Res Audio Failed Login: Missing Login Data May 23 16:28:13 primoultimo volumio[8228]: info: Adding HIGHRESAUDIO REST API Endpoints May 23 16:28:13 primoultimo volumio[8228]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio May 23 16:28:13 primoultimo volumio[8228]: info: Initializing Serial Communication on port /dev/ttyS3 May 23 16:28:13 primoultimo kernel: meson_uart ffd22000.serial: ttyS3 use xtal(24M) 24000000 change 115200 to 115200 May 23 16:28:13 primoultimo volumio[8228]: info: Touch Event Listener Process Starting May 23 16:28:13 primoultimo kernel: aml_tdm_open May 23 16:28:13 primoultimo kernel: Not init audio effects May 23 16:28:13 primoultimo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:tdm@1 May 23 16:28:13 primoultimo kernel: tdm playback mute: 1, lane_cnt = 8 May 23 16:28:13 primoultimo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:tdm@1 May 23 16:28:13 primoultimo volumio[8228]: info: Adding inputs REST Endpoints May 23 16:28:13 primoultimo volumio[8228]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs May 23 16:28:13 primoultimo volumio[8228]: info: Scanning Audio Inputs May 23 16:28:13 primoultimo sudo[8605]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xinput --test-xi2 --root May 23 16:28:13 primoultimo sudo[8605]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:13 primoultimo volumio[8228]: info: Checking against Known Cards name May 23 16:28:13 primoultimo volumio[8228]: info: Checking against Known Cards name May 23 16:28:13 primoultimo volumio[8228]: info: Checking against Known Cards name May 23 16:28:13 primoultimo volumio[8228]: info: Checking against Known Cards name May 23 16:28:13 primoultimo volumio[8228]: info: Checking against Known Cards name May 23 16:28:13 primoultimo volumio[8228]: info: Adding Server instance for streaming May 23 16:28:13 primoultimo sudo[8610]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x25 0x0 May 23 16:28:13 primoultimo sudo[8610]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:13 primoultimo sudo[8610]: pam_unix(sudo:session): session closed for user root May 23 16:28:13 primoultimo sudo[8613]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x28 0x0 May 23 16:28:13 primoultimo sudo[8613]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:13 primoultimo sudo[8613]: pam_unix(sudo:session): session closed for user root May 23 16:28:14 primoultimo sudo[8616]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x29 0x1 May 23 16:28:14 primoultimo sudo[8616]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:14 primoultimo sudo[8616]: pam_unix(sudo:session): session closed for user root May 23 16:28:14 primoultimo sudo[8619]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cset -f -y 4 0x18 0x33 0x1 May 23 16:28:14 primoultimo sudo[8619]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:14 primoultimo sudo[8619]: pam_unix(sudo:session): session closed for user root May 23 16:28:14 primoultimo volumio[8228]: info: MP1 Muting HDMI Output May 23 16:28:14 primoultimo volumio[8228]: info: Starting CEC Event listener May 23 16:28:14 primoultimo volumio[8228]: info: Loading i18n strings for locale it May 23 16:28:14 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile May 23 16:28:14 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:14 primoultimo volumio[8228]: info: FusionDsp - mixtype--------------------- Hardware May 23 16:28:14 primoultimo volumio[8228]: info: Volumio Calling Home May 23 16:28:14 primoultimo volumio[8228]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections May 23 16:28:14 primoultimo volumio[8228]: (node:8228) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead. May 23 16:28:14 primoultimo volumio[8228]: (Use `node --trace-deprecation ...` to show where the warning was created) May 23 16:28:14 primoultimo volumio[8228]: info: Preparing to generate the ALSA configuration file May 23 16:28:14 primoultimo volumio[8228]: info: Stopping AccessToken refresher cron for QOBUZ May 23 16:28:14 primoultimo volumio[8228]: info: AccessToken refresher cron started for QOBUZ May 23 16:28:14 primoultimo volumio[8228]: info: Stopping AccessToken refresher cron May 23 16:28:14 primoultimo volumio[8228]: info: AccessToken refresher cron started May 23 16:28:14 primoultimo volumio[8228]: info: Adding TIDAL REST API Endpoints May 23 16:28:14 primoultimo volumio[8228]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal May 23 16:28:14 primoultimo volumio[8228]: info: Adding QOBUZ REST API Endpoints May 23 16:28:14 primoultimo volumio[8228]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz May 23 16:28:15 primoultimo volumio[8228]: info: Discovery: this is already registered, 540bd688-ac25-4bf9-bd70-55f65b3738d6 May 23 16:28:15 primoultimo volumio[8228]: info: Discovery: Found device Primo&ultimo May 23 16:28:15 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:15 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:15 primoultimo sudo[8629]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service May 23 16:28:15 primoultimo sudo[8629]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:15 primoultimo volumio[8228]: info: Serial port opened successfully May 23 16:28:15 primoultimo volumio[8228]: info: Sending serial start messages May 23 16:28:15 primoultimo sudo[8629]: pam_unix(sudo:session): session closed for user root May 23 16:28:15 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:15 primoultimo volumio[8228]: info: Reporting MCU Network Status: 1 May 23 16:28:15 primoultimo volumio[8228]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 23 16:28:15 primoultimo volumio[8228]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 23 16:28:15 primoultimo volumio[8228]: info: Reading ALSA contributions from plugins. May 23 16:28:15 primoultimo volumio[8228]: error: Cannot start Volumio Streaming Daemon May 23 16:28:15 primoultimo volumio[8228]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 23 16:28:15 primoultimo volumio[8228]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 23 16:28:15 primoultimo volumio[8228]: info: Bluetooth name changed to Primo&ultimo May 23 16:28:15 primoultimo volumio[8228]: info: MPD Permissions set May 23 16:28:15 primoultimo volumio[8228]: info: MPD Permissions set May 23 16:28:15 primoultimo volumio[8228]: info: Upmpdcli Daemon Started May 23 16:28:15 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setDeviceVolumeOverride May 23 16:28:15 primoultimo volumio[8228]: info: Setting Device Volume Override May 23 16:28:15 primoultimo volumio[8228]: No protocol specified May 23 16:28:15 primoultimo volumio[8228]: xcb_connection_has_error() returned true May 23 16:28:15 primoultimo volumio[8228]: info: Applying Volume Override May 23 16:28:15 primoultimo volumio[8228]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 23 16:28:15 primoultimo volumio[8228]: info: Updating Volume Controller Parameters: Device: 0,0 Name: Analog Outputs Mixer: Audio hdmi-out mute Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 May 23 16:28:15 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 23 16:28:15 primoultimo volumio[8228]: info: Enabling external Volume Control May 23 16:28:15 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: inputs , updateVolumeSettings May 23 16:28:15 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: inputs , retrievevolume May 23 16:28:15 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:15 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:15 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:15 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:15 primoultimo volumio[8228]: info: CoreStateMachine::pushState May 23 16:28:15 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:15 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 23 16:28:15 primoultimo volumio[8228]: info: CoreCommandRouter::volumioPushState May 23 16:28:15 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:15 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:15 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output update for this device May 23 16:28:15 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output May 23 16:28:15 primoultimo volumio[8228]: info: Executing endpoint qc_getconfig May 23 16:28:15 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig May 23 16:28:15 primoultimo qobuz-connect[8586]: 20250523 16:28:15.713 [8586.8586] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket May 23 16:28:15 primoultimo volumio[8228]: info: Volumio BT Module successfully started May 23 16:28:15 primoultimo volumio[8228]: info: Volumio called home May 23 16:28:15 primoultimo qobuz-connect[8586]: 20250523 16:28:15.743 [8586.8586] INFO VolumeManager: [0xaaf02918]: Setting new playback volume: 75 May 23 16:28:15 primoultimo qobuz-connect[8586]: 20250523 16:28:15.743 [8586.8586] INFO VolumeManager: [0xaaf02918]: Setting new mute state: 0 May 23 16:28:15 primoultimo qobuz-connect[8586]: 20250523 16:28:15.743 [8586.8586] INFO QobuzConnect: [0xaaf032e8]: Client initialized! May 23 16:28:15 primoultimo qobuz-connect[8586]: 20250523 16:28:15.743 [8586.8586] INFO SampleApp: Starting Avahi advertising, name: Primo&ultimo, service name: _qobuz-connect._tcp May 23 16:28:15 primoultimo volumio[8228]: info: Spotify config file written May 23 16:28:15 primoultimo qobuz-connect[8586]: 20250523 16:28:15.786 [8586.8586] INFO LocalConfigManager: [0xaaf021f8]: Starting Local Configuration server May 23 16:28:15 primoultimo qobuz-connect[8586]: 20250523 16:28:15.786 [8586.8586] INFO SampleApp: Starting Local configuration server May 23 16:28:15 primoultimo qobuz-connect[8586]: 20250523 16:28:15.787 [8586.8586] INFO SampleApp: Connected to UNIX socket client 0xaaef7ed8 May 23 16:28:15 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , setAdditionalSVInfo May 23 16:28:15 primoultimo volumio[8228]: info: Setting Additional System Software info: Hardware Revision: 2.1 May 23 16:28:15 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , setHwFwVersion May 23 16:28:15 primoultimo volumio[8228]: info: Setting HW Firmware info: undefined May 23 16:28:15 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , setHwVersion May 23 16:28:15 primoultimo volumio[8228]: info: Setting HW Version info: 2.1 May 23 16:28:15 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , setAdditionalSVInfo May 23 16:28:15 primoultimo volumio[8228]: info: Setting Additional System Software info: Hardware Revision: 2.1, Firmware Version: 0.3.7 May 23 16:28:15 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , setHwFwVersion May 23 16:28:15 primoultimo volumio[8228]: info: Setting HW Firmware info: 0.3.7 May 23 16:28:15 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , setHwVersion May 23 16:28:15 primoultimo volumio[8228]: info: Setting HW Version info: 2.1 May 23 16:28:15 primoultimo volumio[8228]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff May 23 16:28:15 primoultimo volumio[8228]: info: MCU Signalled Headphone Mode Disabled May 23 16:28:15 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState May 23 16:28:15 primoultimo volumio[8228]: info: Reporting Headphone State: false May 23 16:28:15 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:15 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:15 primoultimo volumio[8228]: info: Updating RAAT Signal Path May 23 16:28:15 primoultimo volumio[8228]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined May 23 16:28:15 primoultimo volumio[8228]: info: MCU Signalled Sleep Mode Disabled May 23 16:28:15 primoultimo qobuz-connect[8586]: 20250523 16:28:15.863 [8586.8586] INFO SampleApp: Playback volume changed: 75 May 23 16:28:15 primoultimo sudo[8638]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 23 16:28:15 primoultimo sudo[8638]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:15 primoultimo mpd[8551]: May 23 16:28 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 23 16:28:15 primoultimo systemd[1]: Started Music Player Daemon. May 23 16:28:15 primoultimo sudo[8483]: pam_unix(sudo:session): session closed for user root May 23 16:28:15 primoultimo sudo[8503]: pam_unix(sudo:session): session closed for user root May 23 16:28:15 primoultimo volumio[8228]: info: Enabling Advanced system settings configuration May 23 16:28:15 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , addAdditionalUISections May 23 16:28:15 primoultimo volumio[8228]: info: Additional UI Settings Added for plugin music_service/inputs May 23 16:28:15 primoultimo volumio[8228]: info: MCU Signalled Auto Boot Mode On Power Active May 23 16:28:15 primoultimo systemd[1]: Stopping go-librespot Daemon... May 23 16:28:15 primoultimo systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM May 23 16:28:15 primoultimo systemd[1]: go-librespot-daemon.service: Succeeded. May 23 16:28:15 primoultimo systemd[1]: Stopped go-librespot Daemon. May 23 16:28:15 primoultimo sudo[8643]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms force on May 23 16:28:15 primoultimo sudo[8643]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:15 primoultimo systemd[1]: Started go-librespot Daemon. May 23 16:28:15 primoultimo go-librespot[8644]: go-librespot daemon starting... May 23 16:28:16 primoultimo sudo[8638]: pam_unix(sudo:session): session closed for user root May 23 16:28:16 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:28:16 primoultimo kernel: fb: osd[0] enable: 1 (Xorg) May 23 16:28:16 primoultimo sudo[8643]: pam_unix(sudo:session): session closed for user root May 23 16:28:16 primoultimo go-librespot[8644]: time="2025-05-23T16:28:16+02:00" level=info msg="running go-librespot 0.2.0" May 23 16:28:16 primoultimo go-librespot[8644]: time="2025-05-23T16:28:16+02:00" level=debug msg="app state loaded" May 23 16:28:16 primoultimo go-librespot[8644]: time="2025-05-23T16:28:16+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 23 16:28:16 primoultimo volumio[8228]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 May 23 16:28:16 primoultimo volumio[8228]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] May 23 16:28:16 primoultimo volumio[8228]: info: QobuzConnect: QOBUZ Connect daemon connected May 23 16:28:16 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:16 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:16 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:16 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:16 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:16 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:16 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:16 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 16:28:16 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 23 16:28:16 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:16 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:16 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:16 primoultimo volumio-remote-updater[2853]: [2025-05-23 16:28:16] [connect] Successful connection May 23 16:28:16 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:16 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:16 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:16 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:16 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 16:28:16 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 23 16:28:16 primoultimo go-librespot[8644]: time="2025-05-23T16:28:16+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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" May 23 16:28:16 primoultimo go-librespot[8644]: time="2025-05-23T16:28:16+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 23 16:28:16 primoultimo go-librespot[8644]: time="2025-05-23T16:28:16+02:00" 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 23 16:28:16 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:16 primoultimo volumio[8228]: info: No need to fix Spotify hosts May 23 16:28:16 primoultimo volumio[8228]: error: Serial API: Failed to decode command: MAXVOL, message: 100 May 23 16:28:16 primoultimo volumio[8228]: error: Serial API: Failed to decode command: MAXVOL, message: 100 May 23 16:28:16 primoultimo go-librespot[8644]: time="2025-05-23T16:28:16+02:00" level=info msg="zeroconf server listening on port 39013" May 23 16:28:16 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 23 16:28:16 primoultimo go-librespot[8644]: time="2025-05-23T16:28:16+02:00" level=debug msg="obtained new client token: AABbUYGwHpfHgXbKqCuUGiCFybJ+E+nr9txO5ir6duc0yyoNGGix0jee3T4DuYeYho/WbSM3PNu2taEKJWOtRMwmAtBYSgMyub1AvJfx7qTHvLJHDc1otuFeSqL7Jz6u/Gn9hI2ThoKf9gyi6X0QDCEwoxyOnNTNXwR8vu+t5zNu47vOTtJna1eNp5YG071uQFynAVQvFMR2bK2Y1wuf3Grre37CeQmTL/9PR0Cc7lD3IPdiBx7Jlttyyw==" May 23 16:28:16 primoultimo go-librespot[8644]: time="2025-05-23T16:28:16+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" May 23 16:28:16 primoultimo volumio[8228]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 May 23 16:28:16 primoultimo volumio[8228]: 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: 10 May 23 16:28:16 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:16 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:16 primoultimo volumio[8228]: info: TidalConnect service stoped! May 23 16:28:16 primoultimo sudo[8669]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms 0 0 0 May 23 16:28:16 primoultimo sudo[8669]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:16 primoultimo sudo[8669]: pam_unix(sudo:session): session closed for user root May 23 16:28:17 primoultimo volumio[8228]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists May 23 16:28:17 primoultimo volumio[8228]: error: FusionDsp - ----failed to create fusiondspfifo :Error: Command failed: /bin/touch /tmp/fusiondsp_stream_params.log && /bin/chmod 666 /tmp/fusiondsp_stream_params.log && /bin/touch /tmp/camilladsp.log && /bin/chmod 666 /tmp/camilladsp.log && /usr/bin/mkfifo -m 646 /tmp/fusiondspfifo May 23 16:28:17 primoultimo volumio[8228]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists May 23 16:28:17 primoultimo volumio[8228]: info: camilladsp spawned new process with pid 8685, instance 1, run: true May 23 16:28:17 primoultimo volumio[8228]: info: camilladsp service started and running in background, instance 1 May 23 16:28:17 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:17 primoultimo kernel: aml_tdm_open May 23 16:28:17 primoultimo kernel: Not init audio effects May 23 16:28:17 primoultimo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:tdm@1 May 23 16:28:17 primoultimo kernel: tdm playback mute: 1, lane_cnt = 8 May 23 16:28:17 primoultimo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:tdm@1 May 23 16:28:17 primoultimo volumio[8228]: No protocol specified May 23 16:28:17 primoultimo volumio[8228]: xcb_connection_has_error() returned true May 23 16:28:17 primoultimo volumio[8228]: info: FusionDsp - AAAAAAAAAAAAAA-> 44100 48000 88200 96000 176400 192000 <-AAAAAAAAAAAAA May 23 16:28:17 primoultimo kernel: aml_tdm_open May 23 16:28:17 primoultimo kernel: Not init audio effects May 23 16:28:17 primoultimo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:tdm@1 May 23 16:28:17 primoultimo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk May 23 16:28:17 primoultimo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk May 23 16:28:17 primoultimo kernel: set mclk:11289600, mpll:22579200, get mclk:11289593, mpll:22579186 May 23 16:28:17 primoultimo kernel: asoc aml_dai_set_tdm_fmt, 0x4001, ffffffc03d29d818, id(1), clksel(1) May 23 16:28:17 primoultimo kernel: aml_dai_set_tdm_fmt(), fmt not change May 23 16:28:17 primoultimo kernel: dump_pcm_setting(ffffffc03d29d818) May 23 16:28:17 primoultimo kernel: pcm_mode(1) May 23 16:28:17 primoultimo kernel: sysclk(11289600) May 23 16:28:17 primoultimo kernel: sysclk_bclk_ratio(4) May 23 16:28:17 primoultimo kernel: bclk(2822400) May 23 16:28:17 primoultimo kernel: bclk_lrclk_ratio(64) May 23 16:28:17 primoultimo kernel: lrclk(44100) May 23 16:28:17 primoultimo kernel: tx_mask(0x3) May 23 16:28:17 primoultimo kernel: rx_mask(0x3) May 23 16:28:17 primoultimo kernel: slots(2) May 23 16:28:17 primoultimo kernel: slot_width(32) May 23 16:28:17 primoultimo kernel: lane_mask_in(0x2) May 23 16:28:17 primoultimo kernel: lane_mask_out(0x1) May 23 16:28:17 primoultimo kernel: lane_oe_mask_in(0x0) May 23 16:28:17 primoultimo kernel: lane_oe_mask_out(0x0) May 23 16:28:17 primoultimo kernel: lane_lb_mask_in(0x0) May 23 16:28:17 primoultimo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk May 23 16:28:17 primoultimo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk May 23 16:28:17 primoultimo kernel: set mclk:11289600, mpll:22579200, get mclk:11289593, mpll:22579186 May 23 16:28:17 primoultimo kernel: aml_dai_set_clkdiv, div 4, clksel(1) May 23 16:28:17 primoultimo kernel: aml_dai_set_bclk_ratio, select I2S mode May 23 16:28:17 primoultimo kernel: aml_dai_tdm_hw_params(), enable mclk for TDM-B May 23 16:28:17 primoultimo kernel: aml_tdm_prepare(), reset fddr May 23 16:28:17 primoultimo kernel: spdif_a fifo ctrl, frddr:0 type:3, 32 bits, chmask 0x3, swap 0x10 May 23 16:28:17 primoultimo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 May 23 16:28:17 primoultimo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 May 23 16:28:17 primoultimo kernel: tdm playback mute: 0, lane_cnt = 8 May 23 16:28:17 primoultimo volumio[8228]: info: FusionDsp loaded May 23 16:28:17 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 23 16:28:17 primoultimo volumio[8228]: info: FusionDsp - Reporting Fusion DSP Enabled May 23 16:28:17 primoultimo volumio[8228]: info: Adding Signal Path Element [object Object] May 23 16:28:17 primoultimo volumio[8228]: info: Adding fusiondspeq DSP Signal Path Element May 23 16:28:17 primoultimo volumio[8228]: info: Additional DSP elements updated May 23 16:28:17 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:17 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:17 primoultimo volumio[8228]: info: Updating RAAT Signal Path May 23 16:28:17 primoultimo volumio[8228]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined May 23 16:28:17 primoultimo sudo[8697]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service May 23 16:28:17 primoultimo sudo[8697]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:17 primoultimo volumio[8228]: info: FusionDsp - ---- installed callbackRead May 23 16:28:17 primoultimo volumio[8228]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 23 16:28:17 primoultimo volumio[8228]: info: FusionDsp - Loudness is ON true May 23 16:28:17 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:17 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:17 primoultimo volumio[8228]: info: FusionDsp - volume level for loudness 100 gain applied 0.00 May 23 16:28:17 primoultimo volumio[8228]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 23 16:28:17 primoultimo volumio[8228]: info: FusionDsp - Loudness is ON true May 23 16:28:17 primoultimo systemd[1]: Started FusionDsp Daemon. May 23 16:28:17 primoultimo sudo[8697]: pam_unix(sudo:session): session closed for user root May 23 16:28:17 primoultimo volumio[8228]: info: MPD running with PID8551 May 23 16:28:17 primoultimo volumio[8228]: ,establishing connection May 23 16:28:17 primoultimo volumio[8228]: info: Initializing I2S Bus May 23 16:28:17 primoultimo volumio[8228]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ May 23 16:28:17 primoultimo volumio[8228]: SPOTIFY: BQBIT0Ch8KyZ_h_avwe-GT8YO7I6S9s5DO36WqLb0FEvhEJ6HmPLtHnS26591kHUIirW9aEtfnW6Y6zlKmr8lGoLTEcHJAFd-eMrFaGFP5FKhQj7JFCFxZ1Q0xDLj_FxdfAsWYrjLSKJ-pTwsl0eCYZOMwcybfPuybN4lSpLdJpOFpNPV41doKQ-nGz_kKWD9PomdM0teDisKsAWjfUR8_-WFhwsz5DZYTobARY9GTJqFvvZIP-iFbKafhJErPjJXPAsdJNTZ-29moJNOyW4ycYBUMVl5relfzQV8pGN4Ps May 23 16:28:17 primoultimo volumio[8228]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ May 23 16:28:17 primoultimo volumio[8228]: info: New Spotify access token = BQBIT0Ch8KyZ_h_avwe-GT8YO7I6S9s5DO36WqLb0FEvhEJ6HmPLtHnS26591kHUIirW9aEtfnW6Y6zlKmr8lGoLTEcHJAFd-eMrFaGFP5FKhQj7JFCFxZ1Q0xDLj_FxdfAsWYrjLSKJ-pTwsl0eCYZOMwcybfPuybN4lSpLdJpOFpNPV41doKQ-nGz_kKWD9PomdM0teDisKsAWjfUR8_-WFhwsz5DZYTobARY9GTJqFvvZIP-iFbKafhJErPjJXPAsdJNTZ-29moJNOyW4ycYBUMVl5relfzQV8pGN4Ps May 23 16:28:17 primoultimo volumio[8228]: info: Spotify credentials grant success - running version from March 24, 2019 May 23 16:28:17 primoultimo volumio[8228]: error: MPD error: The expression evaluated to a falsy value: May 23 16:28:17 primoultimo volumio[8228]: assert.ok(self.idling) May 23 16:28:17 primoultimo volumio[8228]: error: The expression evaluated to a falsy value: May 23 16:28:17 primoultimo volumio[8228]: assert.ok(self.idling) May 23 16:28:17 primoultimo volumio[8228]: error: MPD error: The expression evaluated to a falsy value: May 23 16:28:17 primoultimo volumio[8228]: assert.ok(self.idling) May 23 16:28:17 primoultimo volumio[8228]: error: The expression evaluated to a falsy value: May 23 16:28:17 primoultimo volumio[8228]: assert.ok(self.idling) May 23 16:28:17 primoultimo volumio-remote-updater[2853]: [2025-05-23 16:28:17] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1748010496 101 May 23 16:28:17 primoultimo volumio[8228]: 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: 11 May 23 16:28:17 primoultimo volumio[8228]: info: Starting Shairport Sync May 23 16:28:17 primoultimo volumio[8228]: info: Starting Shairport Sync May 23 16:28:17 primoultimo sudo[8724]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 23 16:28:17 primoultimo sudo[8724]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:17 primoultimo volumio[8228]: info: Starting Shairport Sync May 23 16:28:18 primoultimo sudo[8726]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 23 16:28:18 primoultimo sudo[8726]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:18 primoultimo volumio[8228]: info: Adding Inputs via Serial API May 23 16:28:18 primoultimo volumio[8228]: info: Adding Advanced Audio Settings via Serial API May 23 16:28:18 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections May 23 16:28:18 primoultimo volumio[8228]: info: Additional UI Settings Added for plugin music_service/inputs May 23 16:28:18 primoultimo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 23 16:28:18 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:18 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:18 primoultimo volumio[8228]: info: CoreStateMachine::pushState May 23 16:28:18 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:18 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 23 16:28:18 primoultimo volumio[8228]: info: CoreCommandRouter::volumioPushState May 23 16:28:18 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:18 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:18 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output update for this device May 23 16:28:18 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output May 23 16:28:18 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:18 primoultimo sudo[8724]: pam_unix(sudo:session): session closed for user root May 23 16:28:18 primoultimo sudo[8729]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 23 16:28:18 primoultimo sudo[8729]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:18 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:18 primoultimo volumio[8228]: info: CoreStateMachine::pushState May 23 16:28:18 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:18 primoultimo volumio[8228]: info: CoreCommandRouter::volumioPushState May 23 16:28:18 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:18 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:18 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output update for this device May 23 16:28:18 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output May 23 16:28:18 primoultimo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 23 16:28:18 primoultimo systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM May 23 16:28:18 primoultimo systemd[1]: shairport-sync.service: Succeeded. May 23 16:28:18 primoultimo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 23 16:28:18 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:18 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:18 primoultimo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 23 16:28:18 primoultimo sudo[8729]: pam_unix(sudo:session): session closed for user root May 23 16:28:18 primoultimo sudo[8726]: pam_unix(sudo:session): session closed for user root May 23 16:28:18 primoultimo volumio[8228]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 May 23 16:28:18 primoultimo volumio[8228]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 23 16:28:18 primoultimo volumio[8228]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect May 23 16:28:18 primoultimo volumio[8228]: info: MRS: Getting audio outputs on start May 23 16:28:18 primoultimo volumio[8228]: info: MRS: Requesting all other devices output May 23 16:28:18 primoultimo volumio[8228]: info: CoreCommandRouter::servicePushState May 23 16:28:18 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:18 primoultimo volumio[8228]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received inputs May 23 16:28:18 primoultimo volumio[8228]: info: CoreCommandRouter::volumiosetSourceActiveno-source May 23 16:28:18 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 23 16:28:18 primoultimo sudo[8735]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 23 16:28:18 primoultimo sudo[8735]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:18 primoultimo volumio[8228]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 23 16:28:18 primoultimo volumio[8228]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 23 16:28:18 primoultimo volumio[8228]: error: updateQueue error: null May 23 16:28:18 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 23 16:28:18 primoultimo systemd[1]: Started Volumio Tidal Connect Service. May 23 16:28:18 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:28:18 primoultimo sudo[8735]: pam_unix(sudo:session): session closed for user root May 23 16:28:18 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 23 16:28:18 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:18 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:18 primoultimo volumio[8228]: info: Shairport-Sync Started May 23 16:28:18 primoultimo volumio[8228]: Error adding Membership: Error: addMembership EINVAL May 23 16:28:18 primoultimo volumio[8228]: info: Shairport-Sync Started May 23 16:28:18 primoultimo volumio[8228]: info: Shairport-Sync Started May 23 16:28:18 primoultimo volumio[8228]: info: Asound.conf file unchanged, so no further update is needed May 23 16:28:18 primoultimo volumio[8228]: info: Output device has changed, restarting MPD May 23 16:28:18 primoultimo sudo[8744]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 23 16:28:18 primoultimo sudo[8744]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:18 primoultimo sudo[8744]: pam_unix(sudo:session): session closed for user root May 23 16:28:18 primoultimo volumio[8228]: info: Output device has changed, restarting Shairport Sync May 23 16:28:18 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:18 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 16:28:18 primoultimo sudo[8747]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 23 16:28:18 primoultimo sudo[8747]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:18 primoultimo systemd[1]: Stopping Music Player Daemon... May 23 16:28:18 primoultimo volumio[8228]: No protocol specified May 23 16:28:18 primoultimo volumio[8228]: xcb_connection_has_error() returned true May 23 16:28:18 primoultimo volumio[8228]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 23 16:28:18 primoultimo volumio[8228]: No protocol specified May 23 16:28:18 primoultimo volumio[8228]: xcb_connection_has_error() returned true May 23 16:28:18 primoultimo volumio[8228]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 23 16:28:18 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:19 primoultimo volumio[8228]: info: QobuzConnect: setDeactiveState invoked May 23 16:28:19 primoultimo systemd[1]: mpd.service: Succeeded. May 23 16:28:19 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:19 primoultimo systemd[1]: Stopped Music Player Daemon. May 23 16:28:19 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:19 primoultimo volumio[8228]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes May 23 16:28:19 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:19 primoultimo volumio[8228]: error: Error starting TidalConnect Cannot read property 'sendRevoke' of undefined {"stack":"TypeError: Cannot read property 'sendRevoke' of undefined\n at ControllerTidalconnect.stopTidalConnect (/volumio/app/plugins/music_service/tidalconnect/tidalconnect_real:1:8526)\n at ControllerTidalconnect.restartService (/volumio/app/plugins/music_service/tidalconnect/tidalconnect_real:1:8818)\n at /volumio/node_modules/v-conf/index.js:165:13\n at /volumio/node_modules/multimap/index.js:150:9\n at Array.forEach ()\n at /volumio/node_modules/multimap/index.js:149:13\n at mapEach (/volumio/node_modules/multimap/index.js:9:5)\n at Multimap.forEachEntry (/volumio/node_modules/multimap/index.js:143:5)\n at Multimap.forEach (/volumio/node_modules/multimap/index.js:148:10)\n at Config.set (/volumio/node_modules/v-conf/index.js:162:20)\n at Promise._successFn (/volumio/app/plugins/audio_interface/alsa_controller/index.js:2107:39)\n at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28)\n at processTicksAndRejections (internal/process/task_queues.js:77:11)"} May 23 16:28:19 primoultimo volumio[8228]: info: Preparing to generate the ALSA configuration file May 23 16:28:19 primoultimo systemd[1]: Starting Music Player Daemon... May 23 16:28:19 primoultimo sudo[8757]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 23 16:28:19 primoultimo sudo[8757]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:19 primoultimo systemd[1]: Stopping Volumio Tidal Connect Service... May 23 16:28:19 primoultimo systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM May 23 16:28:19 primoultimo systemd[1]: vtcs.service: Succeeded. May 23 16:28:19 primoultimo sudo[8755]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 23 16:28:19 primoultimo systemd[1]: Stopped Volumio Tidal Connect Service. May 23 16:28:19 primoultimo sudo[8755]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:19 primoultimo sudo[8757]: pam_unix(sudo:session): session closed for user root May 23 16:28:19 primoultimo sudo[8755]: pam_unix(sudo:session): session closed for user root May 23 16:28:19 primoultimo sudo[8764]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 23 16:28:19 primoultimo sudo[8764]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:19 primoultimo sudo[8764]: pam_unix(sudo:session): session closed for user root May 23 16:28:19 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:28:19 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 23 16:28:19 primoultimo sudo[8768]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 23 16:28:19 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:28:19 primoultimo sudo[8768]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:19 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:28:19 primoultimo qobuz-connect[8586]: 20250523 16:28:19.652 [8586.8586] INFO SampleApp: Stopping Local configuration server May 23 16:28:19 primoultimo systemd[1]: Stopping Volumio Qobuz Connect Service... May 23 16:28:19 primoultimo qobuz-connect[8586]: 20250523 16:28:19.664 [8586.8586] INFO SampleApp: shat down connection on UNIX socket May 23 16:28:19 primoultimo systemd[1]: qobuz-connect.service: Succeeded. May 23 16:28:19 primoultimo systemd[1]: Stopped Volumio Qobuz Connect Service. May 23 16:28:19 primoultimo systemd[1]: Started Volumio Qobuz Connect Service. May 23 16:28:19 primoultimo sudo[8768]: pam_unix(sudo:session): session closed for user root May 23 16:28:19 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:19 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 23 16:28:19 primoultimo volumio[8228]: info: Not Reporting Auto name since its the default one May 23 16:28:20 primoultimo volumio[8228]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 23 16:28:20 primoultimo volumio[8228]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 23 16:28:20 primoultimo volumio[8228]: info: Reading ALSA contributions from plugins. May 23 16:28:20 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:28:20 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 23 16:28:20 primoultimo volumio[8228]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined May 23 16:28:20 primoultimo volumio[8228]: info: MPD Permissions set May 23 16:28:20 primoultimo volumio[8228]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected May 23 16:28:20 primoultimo volumio[8228]: info: QobuzConnect: setDeactiveState invoked May 23 16:28:20 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:20 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:20 primoultimo volumio[8228]: info: go-librespot daemon successfully initialized May 23 16:28:20 primoultimo volumio[8228]: info: Successfully initialized Primo I2S Bus May 23 16:28:20 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:20 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:20 primoultimo volumio[8228]: info: CoreStateMachine::pushState May 23 16:28:20 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:20 primoultimo volumio[8228]: info: CoreCommandRouter::volumioPushState May 23 16:28:20 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:20 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:20 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output update for this device May 23 16:28:20 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output May 23 16:28:20 primoultimo volumio[8228]: error: Help! Some callbacks for volumioPushState are crashing! May 23 16:28:20 primoultimo volumio[8228]: error: Cannot read property 'sendVolumeMute' of undefined May 23 16:28:20 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:20 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:20 primoultimo volumio[8228]: info: CoreStateMachine::pushState May 23 16:28:20 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:20 primoultimo volumio[8228]: info: CoreCommandRouter::volumioPushState May 23 16:28:20 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:20 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:20 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output update for this device May 23 16:28:20 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output May 23 16:28:20 primoultimo volumio[8228]: error: Help! Some callbacks for volumioPushState are crashing! May 23 16:28:20 primoultimo volumio[8228]: error: Cannot read property 'sendVolumeMute' of undefined May 23 16:28:20 primoultimo volumio[8228]: info: Executing endpoint tc_getconfig May 23 16:28:20 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig May 23 16:28:20 primoultimo volumio[8228]: info: Executing endpoint qc_getconfig May 23 16:28:20 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig May 23 16:28:20 primoultimo qobuz-connect[8770]: 20250523 16:28:20.296 [8770.8770] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket May 23 16:28:20 primoultimo qobuz-connect[8770]: 20250523 16:28:20.303 [8770.8770] INFO VolumeManager: [0xac939918]: Setting new playback volume: 75 May 23 16:28:20 primoultimo qobuz-connect[8770]: 20250523 16:28:20.303 [8770.8770] INFO VolumeManager: [0xac939918]: Setting new mute state: 0 May 23 16:28:20 primoultimo qobuz-connect[8770]: 20250523 16:28:20.304 [8770.8770] INFO QobuzConnect: [0xac93a2e8]: Client initialized! May 23 16:28:20 primoultimo qobuz-connect[8770]: 20250523 16:28:20.304 [8770.8770] INFO SampleApp: Starting Avahi advertising, name: Primo&ultimo, service name: _qobuz-connect._tcp May 23 16:28:20 primoultimo qobuz-connect[8770]: 20250523 16:28:20.329 [8770.8770] INFO LocalConfigManager: [0xac9391f8]: Starting Local Configuration server May 23 16:28:20 primoultimo qobuz-connect[8770]: 20250523 16:28:20.329 [8770.8770] INFO SampleApp: Starting Local configuration server May 23 16:28:20 primoultimo qobuz-connect[8770]: 20250523 16:28:20.330 [8770.8770] INFO SampleApp: Connected to UNIX socket client 0xac92eed8 May 23 16:28:20 primoultimo volumio[8228]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] May 23 16:28:20 primoultimo volumio[8228]: info: QobuzConnect: QOBUZ Connect daemon connected May 23 16:28:20 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:20 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:20 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:20 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:20 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:20 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:20 primoultimo qobuz-connect[8770]: 20250523 16:28:20.445 [8770.8770] INFO SampleApp: Playback volume changed: 75 May 23 16:28:20 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 16:28:20 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 23 16:28:20 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:20 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable May 23 16:28:20 primoultimo volumio[8228]: No protocol specified May 23 16:28:20 primoultimo volumio[8228]: xcb_connection_has_error() returned true May 23 16:28:20 primoultimo sudo[8786]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service May 23 16:28:20 primoultimo sudo[8786]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:20 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:20 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:20 primoultimo volumio[8228]: info: Starting Shairport Sync May 23 16:28:20 primoultimo sudo[8786]: pam_unix(sudo:session): session closed for user root May 23 16:28:20 primoultimo sudo[8788]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service May 23 16:28:20 primoultimo sudo[8788]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:21 primoultimo sudo[8790]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 23 16:28:21 primoultimo sudo[8790]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:21 primoultimo systemd[1]: Stopping RAAT DAEMON... May 23 16:28:21 primoultimo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM May 23 16:28:21 primoultimo systemd[1]: raat-daemon.service: Succeeded. May 23 16:28:21 primoultimo systemd[1]: Stopped RAAT DAEMON. May 23 16:28:21 primoultimo systemd[1]: Started RAAT DAEMON. May 23 16:28:21 primoultimo sudo[8788]: pam_unix(sudo:session): session closed for user root May 23 16:28:21 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:28:21 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 23 16:28:21 primoultimo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 23 16:28:21 primoultimo systemd[1]: shairport-sync.service: Succeeded. May 23 16:28:21 primoultimo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 23 16:28:21 primoultimo volumio[8228]: info: Raat Daemon started successfully May 23 16:28:21 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:28:21 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 23 16:28:21 primoultimo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 23 16:28:21 primoultimo sudo[8790]: pam_unix(sudo:session): session closed for user root May 23 16:28:21 primoultimo volumio[8228]: 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: 12 May 23 16:28:21 primoultimo volumio[8228]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 May 23 16:28:21 primoultimo volumio[8228]: info: Executing endpoint restartRAATSocket May 23 16:28:21 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection May 23 16:28:21 primoultimo volumio[8228]: info: Shairport-Sync Started May 23 16:28:21 primoultimo volumio[8228]: info: Asound.conf file written May 23 16:28:21 primoultimo sudo[8808]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf May 23 16:28:21 primoultimo sudo[8808]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:21 primoultimo sudo[8808]: pam_unix(sudo:session): session closed for user root May 23 16:28:21 primoultimo kernel: Fine tdm clk setting range (0~2000000), 11289593 May 23 16:28:21 primoultimo kernel: Fine spdif sysclk setting range(0~2000000), 5644797 May 23 16:28:21 primoultimo kernel: out of value, fixed it May 23 16:28:21 primoultimo kernel: id=0 set inskew=0 May 23 16:28:21 primoultimo volumio[8228]: No protocol specified May 23 16:28:21 primoultimo volumio[8228]: xcb_connection_has_error() returned true May 23 16:28:21 primoultimo volumio[8228]: Found hardware: "AML-AUGESOUND-M" "" "" "" "" May 23 16:28:21 primoultimo volumio[8228]: Hardware is initialized using a generic method May 23 16:28:21 primoultimo volumio[8228]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:eARC_TX CDS:0' : Operation not permitted May 23 16:28:21 primoultimo volumio[8228]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:I2SIn CLK:0' : Operation not permitted May 23 16:28:21 primoultimo volumio[8228]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:SPDIFIN audio samplerate:0' : Operation not permitted May 23 16:28:21 primoultimo volumio[8228]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:SPDIFIN Audio Type:0' : Operation not permitted May 23 16:28:21 primoultimo volumio[8228]: info: Output device has changed, restarting MPD May 23 16:28:21 primoultimo volumio[8228]: info: Output device has changed, restarting Shairport Sync May 23 16:28:21 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:21 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 16:28:21 primoultimo sudo[8815]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 23 16:28:21 primoultimo sudo[8815]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:21 primoultimo sudo[8815]: pam_unix(sudo:session): session closed for user root May 23 16:28:21 primoultimo sudo[8817]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 23 16:28:21 primoultimo sudo[8817]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:21 primoultimo volumio[8228]: No protocol specified May 23 16:28:21 primoultimo volumio[8228]: xcb_connection_has_error() returned true May 23 16:28:21 primoultimo volumio[8228]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 23 16:28:21 primoultimo volumio[8228]: No protocol specified May 23 16:28:21 primoultimo volumio[8228]: xcb_connection_has_error() returned true May 23 16:28:21 primoultimo volumio[8228]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 23 16:28:21 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:21 primoultimo systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM May 23 16:28:21 primoultimo systemd[1]: mpd.service: Succeeded. May 23 16:28:21 primoultimo systemd[1]: Stopped Music Player Daemon. May 23 16:28:21 primoultimo volumio[8228]: info: QobuzConnect: setDeactiveState invoked May 23 16:28:21 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:21 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:21 primoultimo volumio[8228]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes May 23 16:28:21 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:21 primoultimo volumio[8228]: error: Error starting TidalConnect Cannot read property 'sendRevoke' of undefined {"stack":"TypeError: Cannot read property 'sendRevoke' of undefined\n at ControllerTidalconnect.stopTidalConnect (/volumio/app/plugins/music_service/tidalconnect/tidalconnect_real:1:8526)\n at ControllerTidalconnect.restartService (/volumio/app/plugins/music_service/tidalconnect/tidalconnect_real:1:8818)\n at /volumio/node_modules/v-conf/index.js:165:13\n at /volumio/node_modules/multimap/index.js:150:9\n at Array.forEach ()\n at /volumio/node_modules/multimap/index.js:149:13\n at mapEach (/volumio/node_modules/multimap/index.js:9:5)\n at Multimap.forEachEntry (/volumio/node_modules/multimap/index.js:143:5)\n at Multimap.forEach (/volumio/node_modules/multimap/index.js:148:10)\n at Config.set (/volumio/node_modules/v-conf/index.js:162:20)\n at Promise._successFn (/volumio/app/plugins/audio_interface/alsa_controller/index.js:2107:39)\n at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28)\n at processTicksAndRejections (internal/process/task_queues.js:77:11)"} May 23 16:28:21 primoultimo volumio[8228]: info: Preparing to generate the ALSA configuration file May 23 16:28:21 primoultimo systemd[1]: Starting Music Player Daemon... May 23 16:28:22 primoultimo sudo[8828]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 23 16:28:22 primoultimo sudo[8828]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:22 primoultimo sudo[8828]: pam_unix(sudo:session): session closed for user root May 23 16:28:22 primoultimo sudo[8824]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 23 16:28:22 primoultimo sudo[8824]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:22 primoultimo sudo[8835]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 23 16:28:22 primoultimo sudo[8835]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:22 primoultimo volumio[8228]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 23 16:28:22 primoultimo sudo[8824]: pam_unix(sudo:session): session closed for user root May 23 16:28:22 primoultimo volumio[8228]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 23 16:28:22 primoultimo volumio[8228]: info: Reading ALSA contributions from plugins. May 23 16:28:22 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:22 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 23 16:28:22 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:28:22 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 23 16:28:22 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:28:22 primoultimo sudo[8835]: pam_unix(sudo:session): session closed for user root May 23 16:28:22 primoultimo volumio[8228]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined May 23 16:28:22 primoultimo volumio[8228]: info: MPD Permissions set May 23 16:28:22 primoultimo volumio[8228]: info: TidalConnect service started! May 23 16:28:22 primoultimo volumio[8228]: SPOTIFY: User informations: {"country":"IT","display_name":"Spotify2","email":"spotify2@leio.club","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/cn35ujv7pkdo9mqt8s0hp0j05"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/cn35ujv7pkdo9mqt8s0hp0j05","id":"cn35ujv7pkdo9mqt8s0hp0j05","images":[],"product":"free","type":"user","uri":"spotify:user:cn35ujv7pkdo9mqt8s0hp0j05"} May 23 16:28:22 primoultimo volumio[8228]: info: Spotify Successfully logged in May 23 16:28:22 primoultimo volumio[8228]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 23 16:28:22 primoultimo volumio[8228]: info: [1748010502363] CoreMusicLibrary::Adding element Spotify May 23 16:28:22 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 23 16:28:22 primoultimo volumio[8228]: Cannot find translation for source Spotify May 23 16:28:22 primoultimo sudo[8840]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 23 16:28:22 primoultimo sudo[8840]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:22 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:22 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:22 primoultimo volumio[8228]: info: CoreStateMachine::pushState May 23 16:28:22 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:22 primoultimo volumio[8228]: info: CoreCommandRouter::volumioPushState May 23 16:28:22 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:22 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:22 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output update for this device May 23 16:28:22 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output May 23 16:28:22 primoultimo volumio[8228]: error: Help! Some callbacks for volumioPushState are crashing! May 23 16:28:22 primoultimo volumio[8228]: error: Cannot read property 'sendVolumeMute' of undefined May 23 16:28:22 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:22 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:22 primoultimo volumio[8228]: info: CoreStateMachine::pushState May 23 16:28:22 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:22 primoultimo volumio[8228]: info: CoreCommandRouter::volumioPushState May 23 16:28:22 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:22 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:22 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output update for this device May 23 16:28:22 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output May 23 16:28:22 primoultimo volumio[8228]: error: Help! Some callbacks for volumioPushState are crashing! May 23 16:28:22 primoultimo volumio[8228]: error: Cannot read property 'sendVolumeMute' of undefined May 23 16:28:22 primoultimo systemd[1]: Stopping Volumio Qobuz Connect Service... May 23 16:28:22 primoultimo qobuz-connect[8770]: 20250523 16:28:22.492 [8770.8770] INFO SampleApp: Stopping Local configuration server May 23 16:28:22 primoultimo qobuz-connect[8770]: 20250523 16:28:22.503 [8770.8770] INFO SampleApp: shat down connection on UNIX socket May 23 16:28:22 primoultimo systemd[1]: qobuz-connect.service: Succeeded. May 23 16:28:22 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 23 16:28:22 primoultimo volumio[8228]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom May 23 16:28:22 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:22 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:22 primoultimo systemd[1]: Stopped Volumio Qobuz Connect Service. May 23 16:28:22 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetVisibleSources May 23 16:28:22 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 23 16:28:22 primoultimo systemd[1]: Started Volumio Qobuz Connect Service. May 23 16:28:22 primoultimo sudo[8840]: pam_unix(sudo:session): session closed for user root May 23 16:28:22 primoultimo volumio[8228]: info: Listing playlists May 23 16:28:22 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:28:22 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 23 16:28:22 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:22 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:22 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:22 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:22 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:22 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:22 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:22 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 23 16:28:22 primoultimo volumio[8228]: info: Not Reporting Auto name since its the default one May 23 16:28:22 primoultimo volumio[8228]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 14 May 23 16:28:22 primoultimo volumio[8228]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected May 23 16:28:22 primoultimo volumio[8228]: info: QobuzConnect: setDeactiveState invoked May 23 16:28:22 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:22 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:22 primoultimo volumio[8228]: info: TidalConnect service stoped! May 23 16:28:22 primoultimo volumio[8228]: error: MPD error: Error: This socket has been ended by the other party May 23 16:28:22 primoultimo volumio[8228]: error: This socket has been ended by the other party {"code":"EPIPE"} May 23 16:28:22 primoultimo volumio[8228]: error: MPD error: Error: This socket has been ended by the other party May 23 16:28:22 primoultimo volumio[8228]: error: This socket has been ended by the other party {"code":"EPIPE"} May 23 16:28:22 primoultimo volumio[8228]: error: MPD error: Error: This socket has been ended by the other party May 23 16:28:22 primoultimo volumio[8228]: error: This socket has been ended by the other party {"code":"EPIPE"} May 23 16:28:22 primoultimo volumio[8228]: error: MPD error: Error: This socket has been ended by the other party May 23 16:28:22 primoultimo volumio[8228]: error: This socket has been ended by the other party {"code":"EPIPE"} May 23 16:28:22 primoultimo volumio[8228]: error: MPD error: Error: This socket has been ended by the other party May 23 16:28:22 primoultimo volumio[8228]: error: This socket has been ended by the other party {"code":"EPIPE"} May 23 16:28:22 primoultimo volumio[8228]: error: MPD error: Error: This socket has been ended by the other party May 23 16:28:22 primoultimo volumio[8228]: error: This socket has been ended by the other party {"code":"EPIPE"} May 23 16:28:22 primoultimo volumio[8228]: error: MPD error: Error: This socket has been ended by the other party May 23 16:28:22 primoultimo volumio[8228]: error: This socket has been ended by the other party {"code":"EPIPE"} May 23 16:28:22 primoultimo volumio[8228]: error: MPD error: Error: This socket has been ended by the other party May 23 16:28:22 primoultimo volumio[8228]: error: This socket has been ended by the other party {"code":"EPIPE"} May 23 16:28:22 primoultimo volumio[8228]: error: MPD error: Error: This socket has been ended by the other party May 23 16:28:22 primoultimo volumio[8228]: error: This socket has been ended by the other party {"code":"EPIPE"} May 23 16:28:22 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:22 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:23 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:23 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 16:28:23 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 23 16:28:23 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:23 primoultimo volumio[8228]: info: Executing endpoint qc_getconfig May 23 16:28:23 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig May 23 16:28:23 primoultimo qobuz-connect[8842]: 20250523 16:28:23.235 [8842.8842] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket May 23 16:28:23 primoultimo qobuz-connect[8842]: 20250523 16:28:23.242 [8842.8842] INFO VolumeManager: [0xab80c918]: Setting new playback volume: 75 May 23 16:28:23 primoultimo qobuz-connect[8842]: 20250523 16:28:23.243 [8842.8842] INFO VolumeManager: [0xab80c918]: Setting new mute state: 0 May 23 16:28:23 primoultimo qobuz-connect[8842]: 20250523 16:28:23.243 [8842.8842] INFO QobuzConnect: [0xab80d2e8]: Client initialized! May 23 16:28:23 primoultimo qobuz-connect[8842]: 20250523 16:28:23.244 [8842.8842] INFO SampleApp: Starting Avahi advertising, name: Primo&ultimo, service name: _qobuz-connect._tcp May 23 16:28:23 primoultimo qobuz-connect[8842]: 20250523 16:28:23.274 [8842.8842] INFO LocalConfigManager: [0xab80c1f8]: Starting Local Configuration server May 23 16:28:23 primoultimo qobuz-connect[8842]: 20250523 16:28:23.274 [8842.8842] INFO SampleApp: Starting Local configuration server May 23 16:28:23 primoultimo qobuz-connect[8842]: 20250523 16:28:23.275 [8842.8842] INFO SampleApp: Connected to UNIX socket client 0xab801ed8 May 23 16:28:23 primoultimo volumio[8228]: info: Initializing connection to go-librespot Websocket May 23 16:28:23 primoultimo qobuz-connect[8842]: 20250523 16:28:23.386 [8842.8842] INFO SampleApp: Playback volume changed: 75 May 23 16:28:23 primoultimo volumio[8228]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] May 23 16:28:23 primoultimo volumio[8228]: info: QobuzConnect: QOBUZ Connect daemon connected May 23 16:28:23 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable May 23 16:28:23 primoultimo volumio[8228]: No protocol specified May 23 16:28:23 primoultimo volumio[8228]: xcb_connection_has_error() returned true May 23 16:28:23 primoultimo volumio[8228]: info: MCU Signalled Playback Inactive May 23 16:28:23 primoultimo go-librespot[8644]: time="2025-05-23T16:28:23+02:00" level=debug msg="new websocket client" May 23 16:28:23 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:23 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:23 primoultimo volumio[8228]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 23 16:28:23 primoultimo volumio[8228]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 23 16:28:23 primoultimo sudo[8869]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service May 23 16:28:23 primoultimo volumio[8228]: info: RAAT: Requesting Headphone Status May 23 16:28:23 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus May 23 16:28:23 primoultimo volumio[8228]: info: Starting Shairport Sync May 23 16:28:23 primoultimo sudo[8869]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:23 primoultimo sudo[8869]: pam_unix(sudo:session): session closed for user root May 23 16:28:23 primoultimo sudo[8871]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 23 16:28:23 primoultimo sudo[8871]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:23 primoultimo volumio[8228]: info: Connection to go-librespot Websocket established May 23 16:28:23 primoultimo sudo[8874]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service May 23 16:28:23 primoultimo sudo[8874]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:23 primoultimo systemd[1]: Started Volumio Tidal Connect Service. May 23 16:28:23 primoultimo sudo[8876]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 23 16:28:24 primoultimo sudo[8876]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:24 primoultimo sudo[8871]: pam_unix(sudo:session): session closed for user root May 23 16:28:24 primoultimo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 23 16:28:24 primoultimo systemd[1]: Stopping RAAT DAEMON... May 23 16:28:24 primoultimo volumio[8228]: info: MCU Signalled Headphone Mode Disabled May 23 16:28:24 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState May 23 16:28:24 primoultimo volumio[8228]: info: Reporting Headphone State: false May 23 16:28:24 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:24 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:24 primoultimo volumio[8228]: info: Updating RAAT Signal Path May 23 16:28:24 primoultimo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM May 23 16:28:24 primoultimo systemd[1]: raat-daemon.service: Succeeded. May 23 16:28:24 primoultimo systemd[1]: Stopped RAAT DAEMON. May 23 16:28:24 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:28:24 primoultimo systemd[1]: shairport-sync.service: Succeeded. May 23 16:28:24 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:28:24 primoultimo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 23 16:28:24 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 23 16:28:24 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 23 16:28:24 primoultimo volumio[8228]: info: Checking for updated MCU Firmware May 23 16:28:24 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 23 16:28:24 primoultimo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 23 16:28:24 primoultimo sudo[8876]: pam_unix(sudo:session): session closed for user root May 23 16:28:24 primoultimo volumio[8228]: info: Firware on device is on latest version, no need to update May 23 16:28:24 primoultimo volumio[8228]: info: Asound.conf file written May 23 16:28:24 primoultimo systemd[1]: Started RAAT DAEMON. May 23 16:28:24 primoultimo sudo[8874]: pam_unix(sudo:session): session closed for user root May 23 16:28:24 primoultimo sudo[8897]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf May 23 16:28:24 primoultimo sudo[8897]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:24 primoultimo sudo[8897]: pam_unix(sudo:session): session closed for user root May 23 16:28:24 primoultimo kernel: Fine tdm clk setting range (0~2000000), 11289593 May 23 16:28:24 primoultimo kernel: Fine spdif sysclk setting range(0~2000000), 5644797 May 23 16:28:24 primoultimo kernel: out of value, fixed it May 23 16:28:24 primoultimo kernel: id=0 set inskew=0 May 23 16:28:24 primoultimo volumio[8228]: No protocol specified May 23 16:28:24 primoultimo volumio[8228]: xcb_connection_has_error() returned true May 23 16:28:24 primoultimo volumio[8228]: Found hardware: "AML-AUGESOUND-M" "" "" "" "" May 23 16:28:24 primoultimo volumio[8228]: Hardware is initialized using a generic method May 23 16:28:24 primoultimo volumio[8228]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:eARC_TX CDS:0' : Operation not permitted May 23 16:28:24 primoultimo volumio[8228]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:I2SIn CLK:0' : Operation not permitted May 23 16:28:24 primoultimo volumio[8228]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:SPDIFIN audio samplerate:0' : Operation not permitted May 23 16:28:24 primoultimo volumio[8228]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:SPDIFIN Audio Type:0' : Operation not permitted May 23 16:28:24 primoultimo volumio[8228]: info: Output device has changed, restarting MPD May 23 16:28:24 primoultimo volumio[8228]: info: Output device has changed, restarting Shairport Sync May 23 16:28:24 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:24 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 16:28:24 primoultimo sudo[8903]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 23 16:28:24 primoultimo sudo[8903]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:24 primoultimo sudo[8903]: pam_unix(sudo:session): session closed for user root May 23 16:28:24 primoultimo sudo[8906]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 23 16:28:24 primoultimo sudo[8906]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:24 primoultimo volumio[8228]: No protocol specified May 23 16:28:24 primoultimo volumio[8228]: xcb_connection_has_error() returned true May 23 16:28:24 primoultimo volumio[8228]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 23 16:28:24 primoultimo volumio[8228]: No protocol specified May 23 16:28:24 primoultimo volumio[8228]: xcb_connection_has_error() returned true May 23 16:28:24 primoultimo volumio[8228]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 23 16:28:24 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:24 primoultimo volumio[8228]: info: QobuzConnect: setDeactiveState invoked May 23 16:28:24 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:24 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:24 primoultimo volumio[8228]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes May 23 16:28:24 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:24 primoultimo volumio[8228]: error: Error starting TidalConnect Cannot read property 'sendRevoke' of undefined {"stack":"TypeError: Cannot read property 'sendRevoke' of undefined\n at ControllerTidalconnect.stopTidalConnect (/volumio/app/plugins/music_service/tidalconnect/tidalconnect_real:1:8526)\n at ControllerTidalconnect.restartService (/volumio/app/plugins/music_service/tidalconnect/tidalconnect_real:1:8818)\n at /volumio/node_modules/v-conf/index.js:165:13\n at /volumio/node_modules/multimap/index.js:150:9\n at Array.forEach ()\n at /volumio/node_modules/multimap/index.js:149:13\n at mapEach (/volumio/node_modules/multimap/index.js:9:5)\n at Multimap.forEachEntry (/volumio/node_modules/multimap/index.js:143:5)\n at Multimap.forEach (/volumio/node_modules/multimap/index.js:148:10)\n at Config.set (/volumio/node_modules/v-conf/index.js:162:20)\n at Promise._successFn (/volumio/app/plugins/audio_interface/alsa_controller/index.js:2107:39)\n at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28)\n at processTicksAndRejections (internal/process/task_queues.js:77:11)"} May 23 16:28:24 primoultimo systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM May 23 16:28:24 primoultimo systemd[1]: mpd.service: Succeeded. May 23 16:28:24 primoultimo systemd[1]: Stopped Music Player Daemon. May 23 16:28:24 primoultimo volumio[8228]: info: Preparing to generate the ALSA configuration file May 23 16:28:24 primoultimo systemd[1]: Starting Music Player Daemon... May 23 16:28:24 primoultimo sudo[8916]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 23 16:28:24 primoultimo sudo[8916]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:25 primoultimo systemd[1]: Stopping Volumio Tidal Connect Service... May 23 16:28:25 primoultimo systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM May 23 16:28:25 primoultimo systemd[1]: vtcs.service: Succeeded. May 23 16:28:25 primoultimo systemd[1]: Stopped Volumio Tidal Connect Service. May 23 16:28:25 primoultimo sudo[8916]: pam_unix(sudo:session): session closed for user root May 23 16:28:25 primoultimo volumio[8228]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 23 16:28:25 primoultimo volumio[8228]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 23 16:28:25 primoultimo volumio[8228]: info: Reading ALSA contributions from plugins. May 23 16:28:25 primoultimo sudo[8913]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 23 16:28:25 primoultimo sudo[8913]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:25 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 23 16:28:25 primoultimo sudo[8913]: pam_unix(sudo:session): session closed for user root May 23 16:28:25 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:28:25 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 23 16:28:25 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:28:25 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:28:25 primoultimo sudo[8922]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 23 16:28:25 primoultimo sudo[8922]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:25 primoultimo volumio[8228]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined May 23 16:28:25 primoultimo volumio[8228]: info: MPD Permissions set May 23 16:28:25 primoultimo sudo[8922]: pam_unix(sudo:session): session closed for user root May 23 16:28:25 primoultimo volumio[8228]: info: Raat Daemon started successfully May 23 16:28:25 primoultimo volumio[8228]: info: Shairport-Sync Started May 23 16:28:25 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:25 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:25 primoultimo volumio[8228]: info: CoreStateMachine::pushState May 23 16:28:25 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:25 primoultimo volumio[8228]: info: CoreCommandRouter::volumioPushState May 23 16:28:25 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:25 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:25 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output update for this device May 23 16:28:25 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output May 23 16:28:25 primoultimo volumio[8228]: error: Help! Some callbacks for volumioPushState are crashing! May 23 16:28:25 primoultimo volumio[8228]: error: Cannot read property 'sendVolumeMute' of undefined May 23 16:28:25 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:25 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:25 primoultimo volumio[8228]: info: CoreStateMachine::pushState May 23 16:28:25 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:25 primoultimo volumio[8228]: info: CoreCommandRouter::volumioPushState May 23 16:28:25 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:25 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:25 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output update for this device May 23 16:28:25 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output May 23 16:28:25 primoultimo volumio[8228]: error: Help! Some callbacks for volumioPushState are crashing! May 23 16:28:25 primoultimo volumio[8228]: error: Cannot read property 'sendVolumeMute' of undefined May 23 16:28:25 primoultimo sudo[8926]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 23 16:28:25 primoultimo sudo[8926]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:25 primoultimo volumio[8228]: info: Executing endpoint restartRAATSocket May 23 16:28:25 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection May 23 16:28:25 primoultimo volumio[8228]: info: Executing endpoint tc_getconfig May 23 16:28:25 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig May 23 16:28:25 primoultimo qobuz-connect[8842]: 20250523 16:28:25.249 [8842.8842] INFO SampleApp: Stopping Local configuration server May 23 16:28:25 primoultimo volumio[8228]: info: Updating RAAT Signal Path May 23 16:28:25 primoultimo volumio[8228]: info: Updating RAAT Signal Path May 23 16:28:25 primoultimo qobuz-connect[8842]: 20250523 16:28:25.259 [8842.8842] INFO SampleApp: shat down connection on UNIX socket May 23 16:28:25 primoultimo systemd[1]: Stopping Volumio Qobuz Connect Service... May 23 16:28:25 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:25 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:25 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:25 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:25 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:25 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:25 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:25 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:25 primoultimo systemd[1]: qobuz-connect.service: Succeeded. May 23 16:28:25 primoultimo systemd[1]: Stopped Volumio Qobuz Connect Service. May 23 16:28:25 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 16:28:25 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 23 16:28:25 primoultimo systemd[1]: Started Volumio Qobuz Connect Service. May 23 16:28:25 primoultimo sudo[8926]: pam_unix(sudo:session): session closed for user root May 23 16:28:25 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:25 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:28:25 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 23 16:28:25 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:25 primoultimo volumio[8228]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected May 23 16:28:25 primoultimo volumio[8228]: info: QobuzConnect: setDeactiveState invoked May 23 16:28:25 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:25 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:25 primoultimo volumio[8228]: info: TidalConnect service stoped! May 23 16:28:25 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:25 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:25 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:25 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:25 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 23 16:28:25 primoultimo volumio[8228]: info: Not Reporting Auto name since its the default one May 23 16:28:25 primoultimo volumio[8228]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 15 May 23 16:28:25 primoultimo volumio[8228]: info: Executing endpoint qc_getconfig May 23 16:28:25 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig May 23 16:28:25 primoultimo qobuz-connect[8931]: 20250523 16:28:25.714 [8931.8931] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket May 23 16:28:25 primoultimo volumio[8228]: info: Starting Shairport Sync May 23 16:28:25 primoultimo qobuz-connect[8931]: 20250523 16:28:25.727 [8931.8931] INFO VolumeManager: [0xab4e4918]: Setting new playback volume: 75 May 23 16:28:25 primoultimo qobuz-connect[8931]: 20250523 16:28:25.728 [8931.8931] INFO VolumeManager: [0xab4e4918]: Setting new mute state: 0 May 23 16:28:25 primoultimo qobuz-connect[8931]: 20250523 16:28:25.729 [8931.8931] INFO QobuzConnect: [0xab4e52e8]: Client initialized! May 23 16:28:25 primoultimo qobuz-connect[8931]: 20250523 16:28:25.729 [8931.8931] INFO SampleApp: Starting Avahi advertising, name: Primo&ultimo, service name: _qobuz-connect._tcp May 23 16:28:25 primoultimo qobuz-connect[8931]: 20250523 16:28:25.750 [8931.8931] INFO LocalConfigManager: [0xab4e41f8]: Starting Local Configuration server May 23 16:28:25 primoultimo qobuz-connect[8931]: 20250523 16:28:25.750 [8931.8931] INFO SampleApp: Starting Local configuration server May 23 16:28:25 primoultimo qobuz-connect[8931]: 20250523 16:28:25.751 [8931.8931] INFO SampleApp: Connected to UNIX socket client 0xab4d9ed8 May 23 16:28:25 primoultimo volumio[8228]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] May 23 16:28:25 primoultimo volumio[8228]: info: QobuzConnect: QOBUZ Connect daemon connected May 23 16:28:25 primoultimo volumio[8228]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 23 16:28:25 primoultimo volumio[8228]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 23 16:28:25 primoultimo sudo[8953]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 23 16:28:25 primoultimo sudo[8953]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:25 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable May 23 16:28:25 primoultimo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 23 16:28:25 primoultimo qobuz-connect[8931]: 20250523 16:28:25.865 [8931.8931] INFO SampleApp: Playback volume changed: 75 May 23 16:28:25 primoultimo sudo[8956]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 23 16:28:25 primoultimo sudo[8956]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:25 primoultimo systemd[1]: shairport-sync.service: Succeeded. May 23 16:28:25 primoultimo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 23 16:28:25 primoultimo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 23 16:28:25 primoultimo sudo[8953]: pam_unix(sudo:session): session closed for user root May 23 16:28:25 primoultimo volumio[8228]: No protocol specified May 23 16:28:25 primoultimo volumio[8228]: xcb_connection_has_error() returned true May 23 16:28:25 primoultimo systemd[1]: Started Volumio Tidal Connect Service. May 23 16:28:25 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:28:26 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 23 16:28:26 primoultimo sudo[8956]: pam_unix(sudo:session): session closed for user root May 23 16:28:26 primoultimo volumio[8228]: info: Asound.conf file unchanged, so no further update is needed May 23 16:28:26 primoultimo volumio[8228]: info: Output device has changed, restarting MPD May 23 16:28:26 primoultimo sudo[8963]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service May 23 16:28:26 primoultimo sudo[8963]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:26 primoultimo sudo[8970]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 23 16:28:26 primoultimo sudo[8963]: pam_unix(sudo:session): session closed for user root May 23 16:28:26 primoultimo sudo[8970]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:26 primoultimo volumio[8228]: info: Output device has changed, restarting Shairport Sync May 23 16:28:26 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:26 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 16:28:26 primoultimo sudo[8970]: pam_unix(sudo:session): session closed for user root May 23 16:28:26 primoultimo sudo[8972]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service May 23 16:28:26 primoultimo sudo[8972]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:26 primoultimo sudo[8974]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 23 16:28:26 primoultimo sudo[8974]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:26 primoultimo systemd[1]: Stopping RAAT DAEMON... May 23 16:28:26 primoultimo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM May 23 16:28:26 primoultimo systemd[1]: raat-daemon.service: Succeeded. May 23 16:28:26 primoultimo systemd[1]: Stopped RAAT DAEMON. May 23 16:28:26 primoultimo systemd[1]: Started RAAT DAEMON. May 23 16:28:26 primoultimo sudo[8972]: pam_unix(sudo:session): session closed for user root May 23 16:28:26 primoultimo volumio[8228]: No protocol specified May 23 16:28:26 primoultimo volumio[8228]: xcb_connection_has_error() returned true May 23 16:28:26 primoultimo volumio[8228]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 23 16:28:26 primoultimo volumio[8228]: No protocol specified May 23 16:28:26 primoultimo volumio[8228]: xcb_connection_has_error() returned true May 23 16:28:26 primoultimo volumio[8228]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 23 16:28:26 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:26 primoultimo volumio[8228]: info: QobuzConnect: setDeactiveState invoked May 23 16:28:26 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:26 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:26 primoultimo volumio[8228]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes May 23 16:28:26 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:26 primoultimo volumio[8228]: error: Error starting TidalConnect Cannot read property 'sendRevoke' of undefined {"stack":"TypeError: Cannot read property 'sendRevoke' of undefined\n at ControllerTidalconnect.stopTidalConnect (/volumio/app/plugins/music_service/tidalconnect/tidalconnect_real:1:8526)\n at ControllerTidalconnect.restartService (/volumio/app/plugins/music_service/tidalconnect/tidalconnect_real:1:8818)\n at /volumio/node_modules/v-conf/index.js:165:13\n at /volumio/node_modules/multimap/index.js:150:9\n at Array.forEach ()\n at /volumio/node_modules/multimap/index.js:149:13\n at mapEach (/volumio/node_modules/multimap/index.js:9:5)\n at Multimap.forEachEntry (/volumio/node_modules/multimap/index.js:143:5)\n at Multimap.forEach (/volumio/node_modules/multimap/index.js:148:10)\n at Config.set (/volumio/node_modules/v-conf/index.js:162:20)\n at Promise._successFn (/volumio/app/plugins/audio_interface/alsa_controller/index.js:2107:39)\n at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28)\n at processTicksAndRejections (internal/process/task_queues.js:77:11)"} May 23 16:28:26 primoultimo systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM May 23 16:28:26 primoultimo systemd[1]: mpd.service: Succeeded. May 23 16:28:26 primoultimo systemd[1]: Stopped Music Player Daemon. May 23 16:28:26 primoultimo systemd[1]: Starting Music Player Daemon... May 23 16:28:26 primoultimo sudo[8995]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 23 16:28:26 primoultimo sudo[8995]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:26 primoultimo systemd[1]: Stopping Volumio Tidal Connect Service... May 23 16:28:26 primoultimo systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM May 23 16:28:26 primoultimo systemd[1]: vtcs.service: Succeeded. May 23 16:28:26 primoultimo systemd[1]: Stopped Volumio Tidal Connect Service. May 23 16:28:26 primoultimo sudo[8995]: pam_unix(sudo:session): session closed for user root May 23 16:28:26 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:28:26 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 23 16:28:26 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 23 16:28:26 primoultimo sudo[8994]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 23 16:28:26 primoultimo sudo[8994]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:26 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:28:26 primoultimo sudo[9004]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 23 16:28:26 primoultimo sudo[9004]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:26 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 23 16:28:26 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:28:26 primoultimo sudo[8994]: pam_unix(sudo:session): session closed for user root May 23 16:28:26 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:26 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:26 primoultimo volumio[8228]: info: Shairport-Sync Started May 23 16:28:26 primoultimo sudo[9004]: pam_unix(sudo:session): session closed for user root May 23 16:28:26 primoultimo volumio[8228]: info: Executing endpoint restartRAATSocket May 23 16:28:26 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection May 23 16:28:26 primoultimo volumio[8228]: info: Executing endpoint tc_getconfig May 23 16:28:26 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig May 23 16:28:26 primoultimo volumio[8228]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined May 23 16:28:26 primoultimo volumio[8228]: info: MPD Permissions set May 23 16:28:26 primoultimo volumio[8228]: info: Raat Daemon started successfully May 23 16:28:26 primoultimo volumio[8228]: info: RAAT: Requesting Headphone Status May 23 16:28:26 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus May 23 16:28:26 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:26 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:26 primoultimo volumio[8228]: info: CoreStateMachine::pushState May 23 16:28:26 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:26 primoultimo volumio[8228]: info: CoreCommandRouter::volumioPushState May 23 16:28:26 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:26 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:26 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output update for this device May 23 16:28:26 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output May 23 16:28:26 primoultimo volumio[8228]: error: Help! Some callbacks for volumioPushState are crashing! May 23 16:28:26 primoultimo volumio[8228]: error: Cannot read property 'sendVolumeMute' of undefined May 23 16:28:26 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:26 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:26 primoultimo volumio[8228]: info: CoreStateMachine::pushState May 23 16:28:26 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:26 primoultimo volumio[8228]: info: CoreCommandRouter::volumioPushState May 23 16:28:26 primoultimo sudo[9007]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 23 16:28:26 primoultimo sudo[9007]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:26 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:26 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:26 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output update for this device May 23 16:28:26 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output May 23 16:28:26 primoultimo volumio[8228]: error: Help! Some callbacks for volumioPushState are crashing! May 23 16:28:26 primoultimo volumio[8228]: error: Cannot read property 'sendVolumeMute' of undefined May 23 16:28:26 primoultimo volumio[8228]: info: MCU Signalled Headphone Mode Disabled May 23 16:28:26 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState May 23 16:28:26 primoultimo volumio[8228]: info: Reporting Headphone State: false May 23 16:28:26 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:26 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:26 primoultimo volumio[8228]: info: Updating RAAT Signal Path May 23 16:28:26 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:26 primoultimo qobuz-connect[8931]: 20250523 16:28:26.988 [8931.8931] INFO SampleApp: Stopping Local configuration server May 23 16:28:27 primoultimo qobuz-connect[8931]: 20250523 16:28:26.998 [8931.8931] INFO SampleApp: shat down connection on UNIX socket May 23 16:28:26 primoultimo systemd[1]: Stopping Volumio Qobuz Connect Service... May 23 16:28:27 primoultimo systemd[1]: qobuz-connect.service: Succeeded. May 23 16:28:27 primoultimo systemd[1]: Stopped Volumio Qobuz Connect Service. May 23 16:28:27 primoultimo systemd[1]: Started Volumio Qobuz Connect Service. May 23 16:28:27 primoultimo sudo[9007]: pam_unix(sudo:session): session closed for user root May 23 16:28:27 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:27 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:27 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:27 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 23 16:28:27 primoultimo volumio[8228]: info: Not Reporting Auto name since its the default one May 23 16:28:27 primoultimo volumio[8228]: info: Getting Spotify volume May 23 16:28:27 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:27 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:27 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:27 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:27 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:27 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 16:28:27 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 23 16:28:27 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:27 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:28:27 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 23 16:28:27 primoultimo volumio[8228]: info: TidalConnect service started! May 23 16:28:27 primoultimo volumio[8228]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected May 23 16:28:27 primoultimo volumio[8228]: info: QobuzConnect: setDeactiveState invoked May 23 16:28:27 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:27 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:27 primoultimo volumio[8228]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 15 May 23 16:28:27 primoultimo volumio[8228]: info: Executing endpoint qc_getconfig May 23 16:28:27 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig May 23 16:28:27 primoultimo qobuz-connect[9012]: 20250523 16:28:27.337 [9012.9012] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket May 23 16:28:27 primoultimo volumio[8228]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 16 May 23 16:28:27 primoultimo qobuz-connect[9012]: 20250523 16:28:27.352 [9012.9012] INFO VolumeManager: [0xacd77918]: Setting new playback volume: 75 May 23 16:28:27 primoultimo qobuz-connect[9012]: 20250523 16:28:27.352 [9012.9012] INFO VolumeManager: [0xacd77918]: Setting new mute state: 0 May 23 16:28:27 primoultimo qobuz-connect[9012]: 20250523 16:28:27.353 [9012.9012] INFO QobuzConnect: [0xacd782e8]: Client initialized! May 23 16:28:27 primoultimo qobuz-connect[9012]: 20250523 16:28:27.354 [9012.9012] INFO SampleApp: Starting Avahi advertising, name: Primo&ultimo, service name: _qobuz-connect._tcp May 23 16:28:27 primoultimo volumio[8228]: info: Starting Shairport Sync May 23 16:28:27 primoultimo qobuz-connect[9012]: 20250523 16:28:27.385 [9012.9012] INFO LocalConfigManager: [0xacd771f8]: Starting Local Configuration server May 23 16:28:27 primoultimo qobuz-connect[9012]: 20250523 16:28:27.385 [9012.9012] INFO SampleApp: Starting Local configuration server May 23 16:28:27 primoultimo qobuz-connect[9012]: 20250523 16:28:27.386 [9012.9012] INFO SampleApp: Connected to UNIX socket client 0xacd6ced8 May 23 16:28:27 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable May 23 16:28:27 primoultimo sudo[9025]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 23 16:28:27 primoultimo sudo[9025]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:27 primoultimo qobuz-connect[9012]: 20250523 16:28:27.487 [9012.9012] INFO SampleApp: Playback volume changed: 75 May 23 16:28:27 primoultimo volumio[8228]: No protocol specified May 23 16:28:27 primoultimo volumio[8228]: xcb_connection_has_error() returned true May 23 16:28:27 primoultimo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 23 16:28:27 primoultimo systemd[1]: shairport-sync.service: Succeeded. May 23 16:28:27 primoultimo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 23 16:28:27 primoultimo systemd[1]: shairport-sync.service: Start request repeated too quickly. May 23 16:28:27 primoultimo systemd[1]: shairport-sync.service: Failed with result 'start-limit-hit'. May 23 16:28:27 primoultimo systemd[1]: Failed to start Shairport Sync - AirPlay Audio Receiver. May 23 16:28:27 primoultimo sudo[9025]: pam_unix(sudo:session): session closed for user root May 23 16:28:27 primoultimo volumio[8228]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] May 23 16:28:27 primoultimo volumio[8228]: info: QobuzConnect: QOBUZ Connect daemon connected May 23 16:28:27 primoultimo sudo[9030]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service May 23 16:28:27 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:28:27 primoultimo sudo[9030]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:27 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 23 16:28:27 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:27 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:27 primoultimo volumio[8228]: info: Shairport-sync error: Error: Command failed: /usr/bin/sudo /bin/systemctl restart shairport-sync May 23 16:28:27 primoultimo volumio[8228]: Job for shairport-sync.service failed. May 23 16:28:27 primoultimo volumio[8228]: See "systemctl status shairport-sync.service" and "journalctl -xe" for details. May 23 16:28:27 primoultimo sudo[9030]: pam_unix(sudo:session): session closed for user root May 23 16:28:27 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:27 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:27 primoultimo sudo[9032]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service May 23 16:28:27 primoultimo volumio[8228]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 16:28:27 primoultimo volumio[8228]: SPOTIFY: SPOTIFY VOLUME undefined May 23 16:28:27 primoultimo volumio[8228]: SPOTIFY: VOLUMIO VOLUME 100 May 23 16:28:27 primoultimo volumio[8228]: info: Aligning Spotify Volume to Volumio Volume May 23 16:28:27 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:27 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:27 primoultimo volumio[8228]: info: Setting Spotify Volume from Volumio: 100 May 23 16:28:27 primoultimo sudo[9032]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:27 primoultimo systemd[1]: Stopping RAAT DAEMON... May 23 16:28:27 primoultimo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM May 23 16:28:27 primoultimo systemd[1]: raat-daemon.service: Succeeded. May 23 16:28:27 primoultimo systemd[1]: Stopped RAAT DAEMON. May 23 16:28:27 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:28:27 primoultimo systemd[1]: Started RAAT DAEMON. May 23 16:28:27 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 23 16:28:27 primoultimo sudo[9032]: pam_unix(sudo:session): session closed for user root May 23 16:28:27 primoultimo volumio[8228]: info: Raat Daemon started successfully May 23 16:28:27 primoultimo volumio[8228]: info: [yt-cast-receiver] DIAL server listening on port 8098 May 23 16:28:28 primoultimo volumio[8228]: info: Executing endpoint restartRAATSocket May 23 16:28:28 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection May 23 16:28:28 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:28 primoultimo volumio[8228]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 15 May 23 16:28:28 primoultimo volumio[8228]: info: TidalConnect service stoped! May 23 16:28:28 primoultimo volumio[8228]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 23 16:28:28 primoultimo volumio[8228]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 23 16:28:28 primoultimo sudo[9071]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 23 16:28:28 primoultimo sudo[9071]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:28 primoultimo systemd[1]: Started Volumio Tidal Connect Service. May 23 16:28:28 primoultimo sudo[9071]: pam_unix(sudo:session): session closed for user root May 23 16:28:28 primoultimo volumio[8228]: info: Executing endpoint tc_getconfig May 23 16:28:28 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig May 23 16:28:28 primoultimo vtcs[9073]: STARTING TidalConnect services, version: 1.4.0.34 May 23 16:28:28 primoultimo vtcs[9073]: STARTED TidalConnect services. May 23 16:28:28 primoultimo volumio[8228]: info: Executing endpoint tc_connect May 23 16:28:28 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect May 23 16:28:28 primoultimo volumio[8228]: info: Connecting to TidalConnect May 23 16:28:28 primoultimo volumio[8228]: info: CoreCommandRouter::servicePushState May 23 16:28:28 primoultimo volumio[8228]: info: CoreStateMachine::pushState May 23 16:28:28 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:28 primoultimo volumio[8228]: info: CoreCommandRouter::volumioPushState May 23 16:28:28 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:28 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:28 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output update for this device May 23 16:28:28 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output May 23 16:28:28 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:28 primoultimo volumio[8228]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received tidalconnect May 23 16:28:28 primoultimo volumio[8228]: info: CoreCommandRouter::servicePushState May 23 16:28:28 primoultimo volumio[8228]: info: CoreStateMachine::pushState May 23 16:28:28 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:28 primoultimo volumio[8228]: info: CoreCommandRouter::volumioPushState May 23 16:28:28 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:28 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:28 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output update for this device May 23 16:28:28 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output May 23 16:28:28 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:28 primoultimo volumio[8228]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received tidalconnect May 23 16:28:29 primoultimo volumio[8228]: info: RAAT: Requesting Headphone Status May 23 16:28:29 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus May 23 16:28:29 primoultimo volumio[8228]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 16:28:29 primoultimo volumio[8228]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 16:28:29 primoultimo volumio[8228]: info: Updating RAAT Signal Path May 23 16:28:29 primoultimo volumio[8228]: info: Updating RAAT Signal Path May 23 16:28:29 primoultimo volumio[8228]: info: TidalConnect service started! May 23 16:28:29 primoultimo volumio[8228]: info: MCU Signalled Headphone Mode Disabled May 23 16:28:29 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState May 23 16:28:29 primoultimo volumio[8228]: info: Reporting Headphone State: false May 23 16:28:29 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:29 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:29 primoultimo volumio[8228]: info: Updating RAAT Signal Path May 23 16:28:29 primoultimo volumio[8228]: SPOTIFY: SETTING SPOTIFY VOLUME 100 May 23 16:28:29 primoultimo volumio[8228]: info: Sending Spotify command with payload to local API: /player/volume May 23 16:28:29 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 23 16:28:29 primoultimo mpd[9008]: May 23 16:28 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 23 16:28:29 primoultimo sudo[8906]: pam_unix(sudo:session): session closed for user root May 23 16:28:29 primoultimo systemd[1]: Started Music Player Daemon. May 23 16:28:29 primoultimo sudo[8817]: pam_unix(sudo:session): session closed for user root May 23 16:28:29 primoultimo sudo[8974]: pam_unix(sudo:session): session closed for user root May 23 16:28:29 primoultimo sudo[8747]: pam_unix(sudo:session): session closed for user root May 23 16:28:29 primoultimo volumio[8228]: error: MPD error: The expression evaluated to a falsy value: May 23 16:28:29 primoultimo volumio[8228]: assert.ok(self.idling) May 23 16:28:29 primoultimo volumio[8228]: error: The expression evaluated to a falsy value: May 23 16:28:29 primoultimo volumio[8228]: assert.ok(self.idling) May 23 16:28:29 primoultimo volumio[8228]: error: MPD error: The expression evaluated to a falsy value: May 23 16:28:29 primoultimo volumio[8228]: assert.ok(self.idling) May 23 16:28:29 primoultimo volumio[8228]: error: The expression evaluated to a falsy value: May 23 16:28:29 primoultimo volumio[8228]: assert.ok(self.idling) May 23 16:28:29 primoultimo volumio[8228]: error: MPD error: The expression evaluated to a falsy value: May 23 16:28:29 primoultimo volumio[8228]: assert.ok(self.idling) May 23 16:28:29 primoultimo volumio[8228]: error: The expression evaluated to a falsy value: May 23 16:28:29 primoultimo volumio[8228]: assert.ok(self.idling) May 23 16:28:29 primoultimo volumio[8228]: error: updateQueue error: null May 23 16:28:29 primoultimo volumio[8228]: info: Completed starting Core Plugins May 23 16:28:29 primoultimo volumio[8228]: info: ------------------------------------------- May 23 16:28:29 primoultimo volumio[8228]: info: ----- MyVolumio plugins startup ---- May 23 16:28:29 primoultimo volumio[8228]: info: ------------------------------------------- May 23 16:28:29 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Fetching plans data.... May 23 16:28:29 primoultimo volumio[8228]: info: TidalConnect service stoped! May 23 16:28:29 primoultimo volumio[8228]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 23 16:28:29 primoultimo volumio[8228]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 23 16:28:29 primoultimo sudo[9104]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 23 16:28:29 primoultimo sudo[9104]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:29 primoultimo sudo[9104]: pam_unix(sudo:session): session closed for user root May 23 16:28:30 primoultimo volumio[8228]: info: RAAT: Requesting Headphone Status May 23 16:28:30 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus May 23 16:28:30 primoultimo volumio[8228]: info: MCU Signalled Headphone Mode Disabled May 23 16:28:30 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState May 23 16:28:30 primoultimo volumio[8228]: info: Reporting Headphone State: false May 23 16:28:30 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:30 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:30 primoultimo volumio[8228]: info: Updating RAAT Signal Path May 23 16:28:31 primoultimo volumio[8228]: info: TidalConnect service started! May 23 16:28:32 primoultimo volumio[8228]: info: TidalConnect service started! May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso May 23 16:28:38 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... May 23 16:28:39 primoultimo volumio[8228]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded May 23 16:28:39 primoultimo volumio[8228]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio May 23 16:28:39 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 16:28:39 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 16:28:39 primoultimo volumio[8228]: info: Starting MyVolumio Remote Streaming Endpoints May 23 16:28:39 primoultimo volumio[8228]: info: MyVolumio login type: Token May 23 16:28:39 primoultimo volumio[8228]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started May 23 16:28:39 primoultimo volumio[8228]: error: [MyVolumio PluginManager] Could not read package.json file: Error: /myvolumio/plugins/music_service/streaming_services//package.json: ENOENT: no such file or directory, open '/myvolumio/plugins/music_service/streaming_services//package.json' May 23 16:28:39 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 23 16:28:40 primoultimo volumio[8228]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN May 23 16:28:41 primoultimo volumio[8228]: info: MyVolumio token set successfully May 23 16:28:41 primoultimo volumio[8228]: info: MYVOLUMIO: Adding device May 23 16:28:41 primoultimo volumio[8228]: info: MYVOLUMIO: Evaluating Server May 23 16:28:42 primoultimo volumio[8228]: info: MyVolumio status changed May 23 16:28:42 primoultimo volumio[8228]: info: Streaming services startup May 23 16:28:42 primoultimo volumio[8228]: info: Starting Streaming Daemon May 23 16:28:42 primoultimo volumio[8228]: info: Removing browser output: myVolumio user plan is not superstar May 23 16:28:42 primoultimo volumio[8228]: info: Removing audio output: May 23 16:28:42 primoultimo volumio[8228]: info: Stoppping Tunnel 1 May 23 16:28:42 primoultimo sudo[9146]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 23 16:28:42 primoultimo sudo[9146]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:42 primoultimo sudo[9146]: pam_unix(sudo:session): session closed for user root May 23 16:28:42 primoultimo volumio[8228]: error: Cannot start Volumio Streaming Daemon May 23 16:28:42 primoultimo volumio[8228]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 23 16:28:42 primoultimo volumio[8228]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 23 16:28:42 primoultimo sudo[9149]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service May 23 16:28:42 primoultimo sudo[9149]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:42 primoultimo sudo[9149]: pam_unix(sudo:session): session closed for user root May 23 16:28:42 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 23 16:28:42 primoultimo volumio[8228]: info: Remote SSH Stopped May 23 16:28:42 primoultimo volumio[8228]: info: Setting Geolocation for MyVolumio to eu6 May 23 16:28:42 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 16:28:42 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 16:28:42 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 16:28:43 primoultimo volumio[8228]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} May 23 16:28:43 primoultimo volumio[8228]: info: Updating MyVolumio device info May 23 16:28:43 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 16:28:44 primoultimo volumio[8228]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} May 23 16:28:44 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 23 16:28:44 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 16:28:44 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 23 16:28:44 primoultimo volumio-remote-updater[2853]: No test mode May 23 16:28:44 primoultimo volumio-remote-updater[2853]: No alpha test mode May 23 16:28:44 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled May 23 16:28:44 primoultimo volumio[8228]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} May 23 16:28:44 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache May 23 16:28:47 primoultimo volumio[8228]: info: MYVOLUMIO: Adding device May 23 16:28:47 primoultimo volumio[8228]: info: MYVOLUMIO: Evaluating Server May 23 16:28:48 primoultimo volumio[8228]: info: Setting Geolocation for MyVolumio to eu10 May 23 16:28:48 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 16:28:49 primoultimo volumio[8228]: info: Updating MyVolumio device info May 23 16:28:49 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 16:28:49 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 16:28:49 primoultimo volumio[8228]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} May 23 16:28:49 primoultimo volumio[8228]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} May 23 16:28:49 primoultimo volumio[8228]: error: MyVolumio Plugin failed to start in a timely fashion May 23 16:28:49 primoultimo volumio[8228]: [Metrics] CommandRouter: 76s 610.80ms May 23 16:28:49 primoultimo volumio[8228]: info: CoreCommandRouter::volumiosetStartupVolume May 23 16:28:49 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:49 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 16:28:49 primoultimo volumio[8228]: info: CoreCommandRouter::Close All Modals sent May 23 16:28:49 primoultimo volumio[8228]: info: CoreCommandRouter::Close All Modals sent May 23 16:28:49 primoultimo volumio[8228]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 23 16:28:49 primoultimo volumio[8228]: info: FusionDsp - ---- read samplerate from file: 44100 May 23 16:28:49 primoultimo volumio[8228]: info: camilladsp stopping service pid 8685... May 23 16:28:49 primoultimo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 May 23 16:28:49 primoultimo kernel: aml_dai_tdm_hw_free(), disable mclk for TDM-B May 23 16:28:49 primoultimo kernel: tdm playback mute: 1, lane_cnt = 8 May 23 16:28:49 primoultimo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:tdm@1 May 23 16:28:49 primoultimo volumio[8228]: info: camilladsp service terminated, instance 1 May 23 16:28:49 primoultimo volumio[8228]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 23 16:28:49 primoultimo volumio[8228]: info: FusionDsp - Loudness is ON true May 23 16:28:49 primoultimo volumio[8228]: info: camilladsp service started and running in background, instance 1 May 23 16:28:49 primoultimo volumio[8228]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 23 16:28:49 primoultimo volumio[8228]: info: FusionDsp - ---- read samplerate from file: 44100 May 23 16:28:49 primoultimo volumio[8228]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 23 16:28:49 primoultimo volumio[8228]: info: FusionDsp - Loudness is ON true May 23 16:28:49 primoultimo volumio[8228]: info: camilladsp spawned new process with pid 9197, instance 1, run: true May 23 16:28:49 primoultimo volumio[8228]: error: FusionDsp - WebSocket error: [object Object] May 23 16:28:49 primoultimo kernel: aml_tdm_open May 23 16:28:49 primoultimo kernel: Not init audio effects May 23 16:28:49 primoultimo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:tdm@1 May 23 16:28:49 primoultimo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk May 23 16:28:49 primoultimo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk May 23 16:28:49 primoultimo kernel: set mclk:11289600, mpll:22579200, get mclk:11289593, mpll:22579186 May 23 16:28:49 primoultimo kernel: asoc aml_dai_set_tdm_fmt, 0x4001, ffffffc03d29d818, id(1), clksel(1) May 23 16:28:49 primoultimo kernel: aml_dai_set_tdm_fmt(), fmt not change May 23 16:28:49 primoultimo kernel: dump_pcm_setting(ffffffc03d29d818) May 23 16:28:49 primoultimo kernel: pcm_mode(1) May 23 16:28:49 primoultimo kernel: sysclk(11289600) May 23 16:28:49 primoultimo kernel: sysclk_bclk_ratio(4) May 23 16:28:49 primoultimo kernel: bclk(2822400) May 23 16:28:49 primoultimo kernel: bclk_lrclk_ratio(64) May 23 16:28:49 primoultimo kernel: lrclk(44100) May 23 16:28:49 primoultimo kernel: tx_mask(0x3) May 23 16:28:49 primoultimo kernel: rx_mask(0x3) May 23 16:28:49 primoultimo kernel: slots(2) May 23 16:28:49 primoultimo kernel: slot_width(32) May 23 16:28:49 primoultimo kernel: lane_mask_in(0x2) May 23 16:28:49 primoultimo kernel: lane_mask_out(0x1) May 23 16:28:49 primoultimo kernel: lane_oe_mask_in(0x0) May 23 16:28:49 primoultimo kernel: lane_oe_mask_out(0x0) May 23 16:28:49 primoultimo kernel: lane_lb_mask_in(0x0) May 23 16:28:49 primoultimo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk May 23 16:28:49 primoultimo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk May 23 16:28:49 primoultimo kernel: set mclk:11289600, mpll:22579200, get mclk:11289593, mpll:22579186 May 23 16:28:49 primoultimo kernel: aml_dai_set_clkdiv, div 4, clksel(1) May 23 16:28:49 primoultimo kernel: aml_dai_set_bclk_ratio, select I2S mode May 23 16:28:50 primoultimo kernel: aml_dai_tdm_hw_params(), enable mclk for TDM-B May 23 16:28:50 primoultimo kernel: aml_tdm_prepare(), reset fddr May 23 16:28:50 primoultimo kernel: spdif_a fifo ctrl, frddr:0 type:3, 32 bits, chmask 0x3, swap 0x10 May 23 16:28:50 primoultimo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 May 23 16:28:50 primoultimo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 May 23 16:28:50 primoultimo kernel: tdm playback mute: 0, lane_cnt = 8 May 23 16:28:50 primoultimo kernel: asoc-aml-card auge_sound: tdm playback enable May 23 16:28:50 primoultimo kernel: spdif_a is set to enable May 23 16:28:50 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable May 23 16:28:50 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 23 16:28:50 primoultimo volumio[8228]: No protocol specified May 23 16:28:50 primoultimo volumio[8228]: xcb_connection_has_error() returned true May 23 16:28:50 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect May 23 16:28:54 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 23 16:28:54 primoultimo volumio[8228]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 May 23 16:28:54 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:28:54 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:55 primoultimo kernel: asoc-aml-card auge_sound: tdm playback stop May 23 16:28:55 primoultimo kernel: spdif_a is set to disable May 23 16:28:55 primoultimo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 May 23 16:28:55 primoultimo kernel: aml_dai_tdm_hw_free(), disable mclk for TDM-B May 23 16:28:55 primoultimo kernel: tdm playback mute: 1, lane_cnt = 8 May 23 16:28:55 primoultimo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:tdm@1 May 23 16:28:55 primoultimo volumio[8228]: info: camilladsp spawned new process with pid 9208, instance 1, run: true May 23 16:28:55 primoultimo kernel: aml_tdm_open May 23 16:28:55 primoultimo kernel: Not init audio effects May 23 16:28:55 primoultimo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:tdm@1 May 23 16:28:55 primoultimo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk May 23 16:28:55 primoultimo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk May 23 16:28:55 primoultimo kernel: set mclk:11289600, mpll:22579200, get mclk:11289593, mpll:22579186 May 23 16:28:55 primoultimo kernel: asoc aml_dai_set_tdm_fmt, 0x4001, ffffffc03d29d818, id(1), clksel(1) May 23 16:28:55 primoultimo kernel: aml_dai_set_tdm_fmt(), fmt not change May 23 16:28:55 primoultimo kernel: dump_pcm_setting(ffffffc03d29d818) May 23 16:28:55 primoultimo kernel: pcm_mode(1) May 23 16:28:55 primoultimo kernel: sysclk(11289600) May 23 16:28:55 primoultimo kernel: sysclk_bclk_ratio(4) May 23 16:28:55 primoultimo kernel: bclk(2822400) May 23 16:28:55 primoultimo kernel: bclk_lrclk_ratio(64) May 23 16:28:55 primoultimo kernel: lrclk(44100) May 23 16:28:55 primoultimo kernel: tx_mask(0x3) May 23 16:28:55 primoultimo kernel: rx_mask(0x3) May 23 16:28:55 primoultimo kernel: slots(2) May 23 16:28:55 primoultimo kernel: slot_width(32) May 23 16:28:55 primoultimo kernel: lane_mask_in(0x2) May 23 16:28:55 primoultimo kernel: lane_mask_out(0x1) May 23 16:28:55 primoultimo kernel: lane_oe_mask_in(0x0) May 23 16:28:55 primoultimo kernel: lane_oe_mask_out(0x0) May 23 16:28:55 primoultimo kernel: lane_lb_mask_in(0x0) May 23 16:28:55 primoultimo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk May 23 16:28:55 primoultimo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk May 23 16:28:55 primoultimo kernel: set mclk:11289600, mpll:22579200, get mclk:11289593, mpll:22579186 May 23 16:28:55 primoultimo kernel: aml_dai_set_clkdiv, div 4, clksel(1) May 23 16:28:55 primoultimo kernel: aml_dai_set_bclk_ratio, select I2S mode May 23 16:28:55 primoultimo kernel: aml_dai_tdm_hw_params(), enable mclk for TDM-B May 23 16:28:55 primoultimo kernel: aml_tdm_prepare(), reset fddr May 23 16:28:55 primoultimo kernel: spdif_a fifo ctrl, frddr:0 type:3, 32 bits, chmask 0x3, swap 0x10 May 23 16:28:55 primoultimo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 May 23 16:28:55 primoultimo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 May 23 16:28:55 primoultimo kernel: tdm playback mute: 0, lane_cnt = 8 May 23 16:28:56 primoultimo volumio[8228]: info: BOOT COMPLETED May 23 16:28:58 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:58 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:58 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 23 16:28:58 primoultimo volumio[8228]: info: Not Reporting Auto name since its the default one May 23 16:28:58 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable May 23 16:28:58 primoultimo volumio[8228]: No protocol specified May 23 16:28:58 primoultimo volumio[8228]: xcb_connection_has_error() returned true May 23 16:28:58 primoultimo sudo[9240]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service May 23 16:28:58 primoultimo sudo[9240]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:58 primoultimo sudo[9240]: pam_unix(sudo:session): session closed for user root May 23 16:28:58 primoultimo sudo[9243]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service May 23 16:28:58 primoultimo sudo[9243]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:28:58 primoultimo systemd[1]: Stopping RAAT DAEMON... May 23 16:28:58 primoultimo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM May 23 16:28:58 primoultimo systemd[1]: raat-daemon.service: Succeeded. May 23 16:28:58 primoultimo systemd[1]: Stopped RAAT DAEMON. May 23 16:28:58 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:28:58 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 23 16:28:58 primoultimo systemd[1]: Started RAAT DAEMON. May 23 16:28:58 primoultimo sudo[9243]: pam_unix(sudo:session): session closed for user root May 23 16:28:58 primoultimo volumio[8228]: info: Raat Daemon started successfully May 23 16:28:58 primoultimo volumio[8228]: info: Executing endpoint restartRAATSocket May 23 16:28:58 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection May 23 16:28:58 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:28:58 primoultimo volumio[8228]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 May 23 16:28:59 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:59 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:28:59 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam May 23 16:28:59 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam May 23 16:28:59 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 23 16:28:59 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetBrowseSources May 23 16:28:59 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 23 16:29:01 primoultimo volumio[8228]: info: RAAT: Requesting Headphone Status May 23 16:29:01 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus May 23 16:29:01 primoultimo volumio[8228]: info: MCU Signalled Headphone Mode Disabled May 23 16:29:01 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState May 23 16:29:01 primoultimo volumio[8228]: info: Reporting Headphone State: false May 23 16:29:01 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:29:01 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:29:01 primoultimo volumio[8228]: info: Updating RAAT Signal Path May 23 16:29:02 primoultimo volumio[8228]: info: Enabling plugin fusiondsp May 23 16:29:02 primoultimo volumio[8228]: info: Loading plugin "fusiondsp"... May 23 16:29:02 primoultimo volumio[8228]: info: Applying required configuration parameters for plugin fusiondsp May 23 16:29:02 primoultimo volumio[8228]: info: Preparing to generate the ALSA configuration file May 23 16:29:02 primoultimo volumio[8228]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 23 16:29:02 primoultimo volumio[8228]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 23 16:29:02 primoultimo volumio[8228]: info: Reading ALSA contributions from plugins. May 23 16:29:02 primoultimo volumio[8228]: info: Asound.conf file unchanged, so no further update is needed May 23 16:29:02 primoultimo volumio[8228]: info: Output device has changed, restarting MPD May 23 16:29:02 primoultimo volumio[8228]: info: Output device has changed, restarting Shairport Sync May 23 16:29:02 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:29:02 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 16:29:02 primoultimo sudo[9265]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 23 16:29:02 primoultimo sudo[9265]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:29:02 primoultimo sudo[9265]: pam_unix(sudo:session): session closed for user root May 23 16:29:02 primoultimo sudo[9267]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 23 16:29:02 primoultimo sudo[9267]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:29:02 primoultimo systemd[1]: Stopping Music Player Daemon... May 23 16:29:02 primoultimo volumio[8228]: No protocol specified May 23 16:29:02 primoultimo volumio[8228]: xcb_connection_has_error() returned true May 23 16:29:02 primoultimo volumio[8228]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 23 16:29:02 primoultimo volumio[8228]: No protocol specified May 23 16:29:02 primoultimo volumio[8228]: xcb_connection_has_error() returned true May 23 16:29:02 primoultimo volumio[8228]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 23 16:29:02 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:29:02 primoultimo volumio[8228]: info: QobuzConnect: setDeactiveState invoked May 23 16:29:02 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:29:02 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:29:02 primoultimo volumio[8228]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes May 23 16:29:02 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:29:02 primoultimo vtcs[9073]: [2025-05-23 16:29:02.949] [tisoc] [warning] [SessionManagerImpl.cpp:243] Illegal State: IDLE May 23 16:29:02 primoultimo vtcs[9073]: [2025-05-23 16:29:02.950] [tisoc] [error] [SpkconServer.cpp:381] recv error. client fd=7 errorno=104 error=Connection reset by peer May 23 16:29:02 primoultimo vtcs[9073]: [2025-05-23 16:29:02.950] [tisoc] [error] [SpkconServer.cpp:376] recv error. socket disconnected May 23 16:29:02 primoultimo systemd[1]: mpd.service: Succeeded. May 23 16:29:02 primoultimo systemd[1]: Stopped Music Player Daemon. May 23 16:29:02 primoultimo systemd[1]: Starting Music Player Daemon... May 23 16:29:03 primoultimo volumio[8228]: info: PLUGIN START: fusiondsp May 23 16:29:03 primoultimo volumio[8228]: info: Loading i18n strings for locale it May 23 16:29:03 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile May 23 16:29:03 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:29:03 primoultimo volumio[8228]: info: FusionDsp - mixtype--------------------- Hardware May 23 16:29:03 primoultimo volumio[8228]: info: Preparing to generate the ALSA configuration file May 23 16:29:03 primoultimo sudo[9277]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 23 16:29:03 primoultimo sudo[9277]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:29:03 primoultimo systemd[1]: Stopping Volumio Tidal Connect Service... May 23 16:29:03 primoultimo volumio[8228]: info: Done. May 23 16:29:03 primoultimo systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM May 23 16:29:03 primoultimo systemd[1]: vtcs.service: Succeeded. May 23 16:29:03 primoultimo systemd[1]: Stopped Volumio Tidal Connect Service. May 23 16:29:03 primoultimo sudo[9277]: pam_unix(sudo:session): session closed for user root May 23 16:29:03 primoultimo sudo[9287]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 23 16:29:03 primoultimo sudo[9287]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:29:03 primoultimo sudo[9276]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 23 16:29:03 primoultimo sudo[9276]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:29:03 primoultimo sudo[9276]: pam_unix(sudo:session): session closed for user root May 23 16:29:03 primoultimo volumio[8228]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 23 16:29:03 primoultimo volumio[8228]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 23 16:29:03 primoultimo volumio[8228]: info: Reading ALSA contributions from plugins. May 23 16:29:03 primoultimo sudo[9287]: pam_unix(sudo:session): session closed for user root May 23 16:29:03 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:29:03 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 23 16:29:03 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:29:03 primoultimo sudo[9295]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 23 16:29:03 primoultimo sudo[9295]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:29:03 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:29:03 primoultimo sudo[9295]: pam_unix(sudo:session): session closed for user root May 23 16:29:03 primoultimo volumio[8228]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined May 23 16:29:03 primoultimo volumio[8228]: info: MPD Permissions set May 23 16:29:03 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:29:03 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:29:03 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:29:03 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:29:03 primoultimo volumio[8228]: info: CoreStateMachine::pushState May 23 16:29:03 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:29:03 primoultimo volumio[8228]: info: CoreCommandRouter::volumioPushState May 23 16:29:03 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:29:03 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:29:03 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output update for this device May 23 16:29:03 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output May 23 16:29:03 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:29:03 primoultimo sudo[9299]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 23 16:29:03 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:29:03 primoultimo volumio[8228]: info: CoreStateMachine::pushState May 23 16:29:03 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:29:03 primoultimo sudo[9299]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 16:29:03 primoultimo volumio[8228]: info: CoreCommandRouter::volumioPushState May 23 16:29:03 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:29:03 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:29:03 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output update for this device May 23 16:29:03 primoultimo volumio[8228]: info: MRS: Pushing multiroomSync output May 23 16:29:03 primoultimo systemd[1]: Stopping Volumio Qobuz Connect Service... May 23 16:29:03 primoultimo qobuz-connect[9012]: 20250523 16:29:03.407 [9012.9012] INFO SampleApp: Stopping Local configuration server May 23 16:29:03 primoultimo qobuz-connect[9012]: 20250523 16:29:03.418 [9012.9012] INFO SampleApp: shat down connection on UNIX socket May 23 16:29:03 primoultimo systemd[1]: qobuz-connect.service: Succeeded. May 23 16:29:03 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: running May 23 16:29:03 primoultimo systemd[1]: Stopped Volumio Qobuz Connect Service. May 23 16:29:03 primoultimo volumio[8228]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 16:29:03 primoultimo volumio[8228]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 23 16:29:03 primoultimo volumio[8228]: info: Updating RAAT Signal Path May 23 16:29:03 primoultimo volumio[8228]: info: Updating RAAT Signal Path May 23 16:29:03 primoultimo volumio[8228]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected May 23 16:29:03 primoultimo volumio[8228]: info: QobuzConnect: setDeactiveState invoked May 23 16:29:03 primoultimo volumio[8228]: info: CoreCommandRouter::volumioGetState May 23 16:29:03 primoultimo volumio[8228]: info: CorePlayQueue::getTrack 0 May 23 16:29:03 primoultimo systemd[1]: Started Volumio Qobuz Connect Service. May 23 16:29:03 primoultimo sudo[9299]: pam_unix(sudo:session): session closed for user root May 23 16:29:03 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:29:03 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:29:03 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:29:03 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:29:03 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:29:03 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:29:03 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:29:03 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:29:03 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 23 16:29:03 primoultimo volumio[8228]: info: Not Reporting Auto name since its the default one May 23 16:29:03 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:29:03 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:29:03 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:29:03 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:29:03 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:29:03 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:29:03 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 23 16:29:03 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 23 16:29:03 primoultimo volumio[8228]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 23 16:29:03 primoultimo volumio[8228]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 23 16:29:03 primoultimo volumio[8228]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 23 16:29:03 primoultimo volumio[8228]: TypeError: Cannot read property 'off' of undefined May 23 16:29:03 primoultimo volumio[8228]: at FusionDsp.onStop (/data/plugins/audio_interface/fusiondsp/index.js:107:15) May 23 16:29:03 primoultimo volumio[8228]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30) May 23 16:29:03 primoultimo volumio[8228]: at PluginManager.disableAndStopPlugin (/volumio/app/pluginmanager.js:1883:8) May 23 16:29:03 primoultimo volumio[8228]: at CoreCommandRouter.disableAndStopPlugin (/volumio/app/index.js:1556:29) May 23 16:29:03 primoultimo volumio[8228]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1401:47) May 23 16:29:03 primoultimo volumio[8228]: at Socket.emit (events.js:400:28) May 23 16:29:03 primoultimo volumio[8228]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 May 23 16:29:03 primoultimo volumio[8228]: at processTicksAndRejections (internal/process/task_queues.js:77:11) May 23 16:29:03 primoultimo volumio[8228]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 23 16:29:04 primoultimo sudo[9323]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-23 16:28 May 23 16:29:04 primoultimo sudo[9323]: 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="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="primo2rev2" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 07:02:33 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Primo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Primo" VOLUMIO_HASH="905581800126f97a879a13768b481efc"