-- Logs begin at Mon 2025-06-16 13:44:51 JST, end at Mon 2025-06-16 15:08:38 JST. -- Jun 16 15:07:02 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 16 15:07:02 rivo volumio[3496]: info: Preload queue cleared Jun 16 15:07:03 rivo go-librespot[3746]: time="2025-06-16T15:07:03+09:00" level=trace msg="sent dealer ping" Jun 16 15:07:03 rivo go-librespot[3746]: time="2025-06-16T15:07:03+09:00" level=trace msg="received dealer pong" Jun 16 15:07:05 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 16 15:07:06 rivo volumio[3496]: info: Preload queue cleared Jun 16 15:07:06 rivo volumio[3496]: info: Preloading song: upnp/http://192.168.0.19:9000/dev0/srv1/control@0$1$13$782$810R119051 Jun 16 15:07:06 rivo volumio[3496]: info: Preloading song: upnp/http://192.168.0.19:9000/dev0/srv1/control@0$1$13$782$810R119307 Jun 16 15:07:06 rivo volumio[3496]: info: Preloading song: upnp/http://192.168.0.19:9000/dev0/srv1/control@0$1$13$782$810R117003 Jun 16 15:07:06 rivo volumio[3496]: info: Preloading song: upnp/http://192.168.0.19:9000/dev0/srv1/control@0$1$13$782$810R118539 Jun 16 15:07:06 rivo volumio[3496]: info: Preloading song: upnp/http://192.168.0.19:9000/dev0/srv1/control@0$1$13$782$810R118027 Jun 16 15:07:06 rivo volumio[3496]: info: Preloading song: upnp/http://192.168.0.19:9000/dev0/srv1/control@0$1$13$782$810R118795 Jun 16 15:07:06 rivo volumio[3496]: info: Preloading song: upnp/http://192.168.0.19:9000/dev0/srv1/control@0$1$13$782$810R117515 Jun 16 15:07:06 rivo volumio[3496]: info: Preloading song: upnp/http://192.168.0.19:9000/dev0/srv1/control@0$1$13$782$810R118283 Jun 16 15:07:06 rivo volumio[3496]: info: Preloading song: upnp/http://192.168.0.19:9000/dev0/srv1/control@0$1$13$782$810R116747 Jun 16 15:07:06 rivo volumio[3496]: info: Preloading song: upnp/http://192.168.0.19:9000/dev0/srv1/control@0$1$13$782$810R117771 Jun 16 15:07:06 rivo volumio[3496]: info: Preloading song: upnp/http://192.168.0.19:9000/dev0/srv1/control@0$1$13$782$810R117259 Jun 16 15:07:06 rivo volumio[3496]: info: Exploding uri upnp/http://192.168.0.19:9000/dev0/srv1/control@0$1$13$782$810R119051 in service upnp_browser Jun 16 15:07:06 rivo volumio[3496]: info: Exploding uri upnp/http://192.168.0.19:9000/dev0/srv1/control@0$1$13$782$810R119307 in service upnp_browser Jun 16 15:07:06 rivo volumio[3496]: info: Exploding uri upnp/http://192.168.0.19:9000/dev0/srv1/control@0$1$13$782$810R117003 in service upnp_browser Jun 16 15:07:06 rivo volumio[3496]: info: Exploding uri upnp/http://192.168.0.19:9000/dev0/srv1/control@0$1$13$782$810R118539 in service upnp_browser Jun 16 15:07:06 rivo volumio[3496]: info: Exploding uri upnp/http://192.168.0.19:9000/dev0/srv1/control@0$1$13$782$810R118027 in service upnp_browser Jun 16 15:07:06 rivo volumio[3496]: info: Exploding uri upnp/http://192.168.0.19:9000/dev0/srv1/control@0$1$13$782$810R118795 in service upnp_browser Jun 16 15:07:06 rivo volumio[3496]: info: Exploding uri upnp/http://192.168.0.19:9000/dev0/srv1/control@0$1$13$782$810R117515 in service upnp_browser Jun 16 15:07:06 rivo volumio[3496]: info: Exploding uri upnp/http://192.168.0.19:9000/dev0/srv1/control@0$1$13$782$810R118283 in service upnp_browser Jun 16 15:07:06 rivo volumio[3496]: info: Exploding uri upnp/http://192.168.0.19:9000/dev0/srv1/control@0$1$13$782$810R116747 in service upnp_browser Jun 16 15:07:06 rivo volumio[3496]: info: Exploding uri upnp/http://192.168.0.19:9000/dev0/srv1/control@0$1$13$782$810R117771 in service upnp_browser Jun 16 15:07:06 rivo volumio[3496]: info: Exploding uri upnp/http://192.168.0.19:9000/dev0/srv1/control@0$1$13$782$810R117259 in service upnp_browser Jun 16 15:07:13 rivo volumio[3496]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 16 15:07:14 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jun 16 15:07:14 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 16 15:07:14 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 16 15:07:14 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 15:07:14 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 15:07:14 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 15:07:14 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 15:07:14 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 15:07:14 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 15:07:14 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 15:07:14 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jun 16 15:07:14 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jun 16 15:07:14 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 16 15:07:14 rivo volumio[3496]: info: Received Get System Info Jun 16 15:07:14 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 16 15:07:14 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 16 15:07:14 rivo volumio[3496]: info: Discovery: Getting this device information Jun 16 15:07:14 rivo volumio[3496]: info: CoreCommandRouter::volumioGetState Jun 16 15:07:14 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 16 15:07:22 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 16 15:07:22 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 16 15:07:22 rivo volumio[3496]: info: Discovery: Getting this device information Jun 16 15:07:22 rivo volumio[3496]: info: CoreCommandRouter::volumioGetState Jun 16 15:07:22 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 16 15:07:29 rivo volumio[3496]: info: CALLMETHOD: audio_interface alsa_controller saveVolumeOptions [object Object] Jun 16 15:07:29 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveVolumeOptions Jun 16 15:07:29 rivo volumio[3496]: info: CoreCommandRouter::volumioGetState Jun 16 15:07:29 rivo volumio[3496]: info: Restoring Previous Volume level: 100 false false Jun 16 15:07:29 rivo volumio[3496]: info: Output device has changed, restarting MPD Jun 16 15:07:29 rivo sudo[17118]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 16 15:07:29 rivo sudo[17118]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 15:07:29 rivo volumio[3496]: info: QobuzConnect: setDeactiveState invoked Jun 16 15:07:29 rivo volumio[3496]: info: CoreCommandRouter::volumioGetState Jun 16 15:07:29 rivo sudo[17118]: pam_unix(sudo:session): session closed for user root Jun 16 15:07:29 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 15:07:29 rivo volumio[3496]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Jun 16 15:07:29 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 15:07:29 rivo sudo[17121]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 16 15:07:29 rivo sudo[17121]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 15:07:29 rivo volumio[3496]: info: Output device has changed, restarting Shairport Sync Jun 16 15:07:29 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 15:07:29 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 16 15:07:29 rivo systemd[1]: Stopping Music Player Daemon... Jun 16 15:07:29 rivo volumio[3496]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 16 15:07:29 rivo volumio[3496]: info: Volume configurations have been set Jun 16 15:07:29 rivo volumio[3496]: info: QobuzConnect: setDeactiveState invoked Jun 16 15:07:29 rivo volumio[3496]: info: CoreCommandRouter::volumioGetState Jun 16 15:07:29 rivo systemd[1]: mpd.service: Succeeded. Jun 16 15:07:29 rivo systemd[1]: Stopped Music Player Daemon. Jun 16 15:07:29 rivo systemd[1]: Starting Music Player Daemon... Jun 16 15:07:29 rivo volumio[3496]: info: CoreCommandRouter::volumioUpdateVolumeSettings Jun 16 15:07:29 rivo volumio[3496]: info: Updating Volume Controller Parameters: Device: 5 Name: Accuphase USB Audio Product7 Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Jun 16 15:07:29 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Jun 16 15:07:29 rivo volumio[3496]: info: Disabling external Volume Control Jun 16 15:07:29 rivo volumio[3496]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 16 15:07:29 rivo volumio[3496]: info: CoreStateMachine::pushState Jun 16 15:07:29 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 16 15:07:29 rivo volumio[3496]: info: CoreCommandRouter::volumioPushState Jun 16 15:07:29 rivo volumio[3496]: info: CoreCommandRouter::volumioGetState Jun 16 15:07:29 rivo volumio[3496]: info: MRS: Pushing multiroomSync output update for this device Jun 16 15:07:29 rivo volumio[3496]: info: MRS: Pushing multiroomSync output Jun 16 15:07:29 rivo sudo[17129]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 16 15:07:29 rivo sudo[17129]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 15:07:29 rivo sudo[17129]: pam_unix(sudo:session): session closed for user root Jun 16 15:07:29 rivo sudo[17146]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Jun 16 15:07:29 rivo sudo[17146]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 15:07:29 rivo sudo[17146]: pam_unix(sudo:session): session closed for user root Jun 16 15:07:29 rivo sudo[17153]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Jun 16 15:07:29 rivo sudo[17153]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 15:07:29 rivo sudo[17154]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Jun 16 15:07:29 rivo sudo[17154]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 15:07:29 rivo volumio[3496]: info: MPD Permissions set Jun 16 15:07:29 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 15:07:29 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 15:07:29 rivo qobuz-connect[7889]: 20250616 15:07:29.949 [7889.7889] INFO SampleApp: Stopping Local configuration server Jun 16 15:07:29 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 15:07:29 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 15:07:29 rivo systemd[1]: Stopping Volumio Qobuz Connect Service... Jun 16 15:07:29 rivo sudo[17154]: pam_unix(sudo:session): session closed for user root Jun 16 15:07:29 rivo qobuz-connect[7889]: 20250616 15:07:29.960 [7889.7889] INFO SampleApp: shat down connection on UNIX socket Jun 16 15:07:29 rivo systemd[1]: qobuz-connect.service: Succeeded. Jun 16 15:07:29 rivo systemd[1]: Stopped Volumio Qobuz Connect Service. Jun 16 15:07:29 rivo systemd[1]: Started Volumio Qobuz Connect Service. Jun 16 15:07:29 rivo sudo[17153]: pam_unix(sudo:session): session closed for user root Jun 16 15:07:29 rivo sudo[17157]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Jun 16 15:07:29 rivo sudo[17157]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 15:07:30 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 16 15:07:30 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jun 16 15:07:30 rivo systemd[1]: Stopping Volumio Qobuz Connect Service... Jun 16 15:07:30 rivo systemd[1]: qobuz-connect.service: Main process exited, code=killed, status=2/INT Jun 16 15:07:30 rivo systemd[1]: qobuz-connect.service: Succeeded. Jun 16 15:07:30 rivo systemd[1]: Stopped Volumio Qobuz Connect Service. Jun 16 15:07:30 rivo systemd[1]: Started Volumio Qobuz Connect Service. Jun 16 15:07:30 rivo sudo[17157]: pam_unix(sudo:session): session closed for user root Jun 16 15:07:30 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 16 15:07:30 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jun 16 15:07:30 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 16 15:07:30 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 16 15:07:30 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 15:07:30 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 15:07:30 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 15:07:30 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 15:07:30 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 15:07:30 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 15:07:30 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 15:07:30 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jun 16 15:07:30 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jun 16 15:07:30 rivo volumio[3496]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Jun 16 15:07:30 rivo volumio[3496]: info: QobuzConnect: setDeactiveState invoked Jun 16 15:07:30 rivo volumio[3496]: info: CoreCommandRouter::volumioGetState Jun 16 15:07:30 rivo volumio[3496]: info: Executing endpoint qc_getconfig Jun 16 15:07:30 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Jun 16 15:07:30 rivo qobuz-connect[17165]: 20250616 15:07:30.301 [17165.17165] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Jun 16 15:07:30 rivo volumio[3496]: info: Starting Shairport Sync Jun 16 15:07:30 rivo qobuz-connect[17165]: 20250616 15:07:30.307 [17165.17165] INFO VolumeManager: [0xac916240]: Setting new playback volume: 75 Jun 16 15:07:30 rivo qobuz-connect[17165]: 20250616 15:07:30.308 [17165.17165] INFO VolumeManager: [0xac916240]: Setting new mute state: 0 Jun 16 15:07:30 rivo qobuz-connect[17165]: 20250616 15:07:30.308 [17165.17165] INFO QobuzConnect: [0xac916c10]: Client initialized! Jun 16 15:07:30 rivo qobuz-connect[17165]: 20250616 15:07:30.308 [17165.17165] INFO SampleApp: Starting Avahi advertising, name: Rivo, service name: _qobuz-connect._tcp Jun 16 15:07:30 rivo qobuz-connect[17165]: 20250616 15:07:30.321 [17165.17165] INFO LocalConfigManager: [0xac915b20]: Starting Local Configuration server Jun 16 15:07:30 rivo qobuz-connect[17165]: 20250616 15:07:30.322 [17165.17165] INFO SampleApp: Starting Local configuration server Jun 16 15:07:30 rivo qobuz-connect[17165]: 20250616 15:07:30.322 [17165.17165] INFO SampleApp: Connected to UNIX socket client 0xac90bed8 Jun 16 15:07:30 rivo volumio[3496]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Jun 16 15:07:30 rivo volumio[3496]: info: QobuzConnect: QOBUZ Connect daemon connected Jun 16 15:07:30 rivo sudo[17175]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 16 15:07:30 rivo sudo[17175]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 15:07:30 rivo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 16 15:07:30 rivo systemd[1]: shairport-sync.service: Succeeded. Jun 16 15:07:30 rivo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 16 15:07:30 rivo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 16 15:07:30 rivo sudo[17175]: pam_unix(sudo:session): session closed for user root Jun 16 15:07:30 rivo volumio[3496]: info: Shairport-Sync Started Jun 16 15:07:30 rivo qobuz-connect[17165]: 20250616 15:07:30.450 [17165.17165] INFO SampleApp: Playback volume changed: 75 Jun 16 15:07:30 rivo volumio[3496]: info: CoreCommandRouter::volumioGetState Jun 16 15:07:31 rivo mpd[17147]: Jun 16 15:07 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 16 15:07:31 rivo systemd[1]: Started Music Player Daemon. Jun 16 15:07:31 rivo sudo[17121]: pam_unix(sudo:session): session closed for user root Jun 16 15:07:31 rivo volumio[3496]: error: updateQueue error: null Jun 16 15:07:33 rivo go-librespot[3746]: time="2025-06-16T15:07:33+09:00" level=trace msg="received accesspoint ping" Jun 16 15:07:33 rivo go-librespot[3746]: time="2025-06-16T15:07:33+09:00" level=trace msg="received accesspoint pong ack" Jun 16 15:07:33 rivo go-librespot[3746]: time="2025-06-16T15:07:33+09:00" level=trace msg="sent dealer ping" Jun 16 15:07:33 rivo volumio[3496]: info: VolumeController::SetAlsaVolume100 Jun 16 15:07:33 rivo volumio[3496]: info: CoreStateMachine::pushState Jun 16 15:07:33 rivo volumio[3496]: info: CoreCommandRouter::volumioPushState Jun 16 15:07:33 rivo go-librespot[3746]: time="2025-06-16T15:07:33+09:00" level=trace msg="received dealer pong" Jun 16 15:07:33 rivo volumio[3496]: info: CoreCommandRouter::volumioGetState Jun 16 15:07:33 rivo volumio[3496]: info: MRS: Pushing multiroomSync output update for this device Jun 16 15:07:33 rivo volumio[3496]: info: MRS: Pushing multiroomSync output Jun 16 15:07:52 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 16 15:07:52 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 16 15:07:52 rivo volumio[3496]: info: Discovery: Getting this device information Jun 16 15:07:52 rivo volumio[3496]: info: CoreCommandRouter::volumioGetState Jun 16 15:07:52 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 16 15:08:03 rivo go-librespot[3746]: time="2025-06-16T15:08:03+09:00" level=trace msg="sent dealer ping" Jun 16 15:08:03 rivo go-librespot[3746]: time="2025-06-16T15:08:03+09:00" level=trace msg="received dealer pong" Jun 16 15:08:10 rivo volumio[3496]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 16 15:08:10 rivo volumio[3496]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 16 15:08:10 rivo volumio[3496]: info: Retrieving Cloud Streaming UI Jun 16 15:08:10 rivo volumio[3496]: info: Getting Tidal Cloud Configuration Jun 16 15:08:10 rivo volumio[3496]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 16 15:08:10 rivo volumio[3496]: info: Getting Qobuz Cloud Configuration Jun 16 15:08:10 rivo volumio[3496]: info: Asking plugin for UI Config Jun 16 15:08:10 rivo volumio[3496]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 16 15:08:10 rivo volumio[3496]: info: Getting Spotify Cloud Configuration Jun 16 15:08:10 rivo volumio[3496]: info: Asking plugin for UI Config Jun 16 15:08:10 rivo volumio[3496]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 16 15:08:10 rivo volumio[3496]: info: Saving Spotify Acccount Jun 16 15:08:10 rivo volumio[3496]: info: Got it Jun 16 15:08:10 rivo volumio[3496]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Jun 16 15:08:10 rivo volumio[3496]: info: Got Tidal Cloud Configuration Jun 16 15:08:10 rivo volumio[3496]: info: Got it Jun 16 15:08:10 rivo volumio[3496]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 16 15:08:10 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jun 16 15:08:10 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 16 15:08:10 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 16 15:08:10 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 16 15:08:10 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 15:08:10 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 15:08:10 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 15:08:10 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 16 15:08:10 rivo volumio[3496]: info: CoreCommandRouter::volumioGetBrowseSources Jun 16 15:08:10 rivo volumio[3496]: info: CoreCommandRouter::volumioGetBrowseSources Jun 16 15:08:10 rivo volumio[3496]: info: CoreCommandRouter::volumioGetBrowseSources Jun 16 15:08:11 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 15:08:12 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jun 16 15:08:14 rivo volumio[3496]: info: Enabling MyMusic plugin bluetooth Jun 16 15:08:14 rivo volumio[3496]: info: Enabling plugin bluetooth Jun 16 15:08:14 rivo volumio[3496]: info: Loading plugin "bluetooth"... Jun 16 15:08:15 rivo volumio[3496]: info: [1750054095235] Starting BluetoothController Jun 16 15:08:15 rivo volumio[3496]: info: PLUGIN START: bluetooth Jun 16 15:08:15 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 16 15:08:15 rivo volumio[3496]: info: Done. Jun 16 15:08:15 rivo sudo[17303]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name Rivo Jun 16 15:08:15 rivo sudo[17303]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 15:08:15 rivo sudo[17303]: pam_unix(sudo:session): session closed for user root Jun 16 15:08:15 rivo volumio[3496]: info: Bluetooth name changed to Rivo Jun 16 15:08:15 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 15:08:18 rivo sudo[17325]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Jun 16 15:08:18 rivo sudo[17325]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 15:08:18 rivo systemd[1]: Started Volumio Bluetooth Module. Jun 16 15:08:18 rivo sudo[17325]: pam_unix(sudo:session): session closed for user root Jun 16 15:08:18 rivo volumio[3496]: info: Volumio BT Module successfully started Jun 16 15:08:18 rivo sudo[17334]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* Jun 16 15:08:18 rivo sudo[17334]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 15:08:18 rivo volumiobt[17327]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory Jun 16 15:08:18 rivo sudo[17334]: pam_unix(sudo:session): session closed for user root Jun 16 15:08:19 rivo sudo[17339]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio Jun 16 15:08:19 rivo sudo[17339]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 15:08:19 rivo volumiobt[17327]: pulseaudio: no process found Jun 16 15:08:19 rivo sudo[17339]: pam_unix(sudo:session): session closed for user root Jun 16 15:08:19 rivo dbus-daemon[2846]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.30' (uid=1000 pid=17343 comm="/usr/bin/pulseaudio --high-priority=true " label="kernel") Jun 16 15:08:19 rivo systemd[1]: Starting RealtimeKit Scheduling Policy Service... Jun 16 15:08:19 rivo kernel: IPVS: Creating netns size=1928 id=3 Jun 16 15:08:19 rivo volumio[3496]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 16 15:08:19 rivo dbus-daemon[2846]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' Jun 16 15:08:19 rivo systemd[1]: Started RealtimeKit Scheduling Policy Service. Jun 16 15:08:19 rivo rtkit-daemon[17344]: Successfully called chroot. Jun 16 15:08:19 rivo rtkit-daemon[17344]: Successfully dropped privileges. Jun 16 15:08:19 rivo rtkit-daemon[17344]: Successfully limited resources. Jun 16 15:08:19 rivo rtkit-daemon[17344]: Running. Jun 16 15:08:19 rivo rtkit-daemon[17344]: Watchdog thread running. Jun 16 15:08:19 rivo rtkit-daemon[17344]: Canary thread running. Jun 16 15:08:19 rivo dbus-daemon[2846]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.31' (uid=0 pid=17344 comm="/usr/lib/rtkit/rtkit-daemon " label="kernel") Jun 16 15:08:19 rivo systemd[1]: Starting Authorization Manager... Jun 16 15:08:19 rivo volumio[3496]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 16 15:08:19 rivo polkitd[17347]: started daemon version 0.105 using authority implementation `local' version `0.105' Jun 16 15:08:19 rivo dbus-daemon[2846]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Jun 16 15:08:19 rivo systemd[1]: Started Authorization Manager. Jun 16 15:08:19 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 15:08:20 rivo pulseaudio[17343]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Jun 16 15:08:20 rivo pulseaudio[17343]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Jun 16 15:08:20 rivo volumiobt[17327]: Applying permissions Jun 16 15:08:20 rivo volumiobt[17327]: Setting BT discoverable and pairable Jun 16 15:08:20 rivo bluetoothd[3305]: Endpoint registered: sender=:1.51 path=/MediaEndpoint/A2DPSource Jun 16 15:08:20 rivo bluetoothd[3305]: Endpoint registered: sender=:1.51 path=/MediaEndpoint/A2DPSink Jun 16 15:08:20 rivo pulseaudio[17343]: Failed to register as a handsfree audio agent with ofono: org.freedesktop.DBus.Error.ServiceUnknown: The name org.ofono was not provided by any .service files Jun 16 15:08:20 rivo volumiobt[17327]: Agent registered Jun 16 15:08:20 rivo volumiobt[17327]: [bluetooth]# -e power on Jun 16 15:08:20 rivo volumiobt[17327]: Invalid command in menu main: -e Jun 16 15:08:20 rivo volumiobt[17327]: Jun 16 15:08:20 rivo volumiobt[17327]: Use "help" for a list of available commands in a menu. Jun 16 15:08:20 rivo volumiobt[17327]: Use "menu " if you want to enter any submenu. Jun 16 15:08:20 rivo volumiobt[17327]: Use "back" if you want to return to menu main. Jun 16 15:08:20 rivo volumiobt[17327]: [bluetooth]# agent on Jun 16 15:08:20 rivo volumiobt[17327]: Agent is already registered Jun 16 15:08:20 rivo volumiobt[17327]: [bluetooth]# discoverable on Jun 16 15:08:20 rivo volumiobt[17327]: [bluetooth]# pairable on Jun 16 15:08:20 rivo volumiobt[17327]: [bluetooth]# agent NoInputNoOutput Jun 16 15:08:20 rivo volumiobt[17327]: Agent is already registered Jun 16 15:08:20 rivo volumiobt[17327]: [bluetooth]# default-agent Jun 16 15:08:20 rivo volumiobt[17327]: [bluetooth]# quit Jun 16 15:08:20 rivo volumiobt[17327]: [59B blob data] Jun 16 15:08:22 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 16 15:08:22 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 16 15:08:22 rivo volumio[3496]: info: Discovery: Getting this device information Jun 16 15:08:22 rivo volumio[3496]: info: CoreCommandRouter::volumioGetState Jun 16 15:08:22 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 16 15:08:23 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 15:08:27 rivo volumio[3496]: info: Disabling MyMusic plugin upnp Jun 16 15:08:27 rivo sudo[17384]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Jun 16 15:08:27 rivo sudo[17384]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 16 15:08:27 rivo systemd[1]: Stopping UPnP Renderer front-end to MPD... Jun 16 15:08:27 rivo volumio[3496]: error: Upnp client error: Error: This socket has been ended by the other party Jun 16 15:08:27 rivo volumio[3496]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 16 15:08:27 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 15:08:31 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 15:08:33 rivo go-librespot[3746]: time="2025-06-16T15:08:33+09:00" level=trace msg="sent dealer ping" Jun 16 15:08:33 rivo go-librespot[3746]: time="2025-06-16T15:08:33+09:00" level=trace msg="received dealer pong" Jun 16 15:08:35 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 16 15:08:37 rivo volumio[3496]: info: Enabling MyMusic plugin upnp Jun 16 15:08:37 rivo volumio[3496]: info: Enabling plugin upnp Jun 16 15:08:37 rivo volumio[3496]: info: Loading plugin "upnp"... Jun 16 15:08:37 rivo volumio[3496]: info: [1750054117352] Starting Upmpd Daemon Jun 16 15:08:37 rivo volumio[3496]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 16 15:08:37 rivo volumio[3496]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 16 15:08:37 rivo volumio[3496]: Error: listen EADDRINUSE: address already in use :::6599 Jun 16 15:08:37 rivo volumio[3496]: at Server.setupListenHandle [as _listen2] (net.js:1331:16) Jun 16 15:08:37 rivo volumio[3496]: at listenInCluster (net.js:1379:12) Jun 16 15:08:37 rivo volumio[3496]: at Server.listen (net.js:1465:7) Jun 16 15:08:37 rivo volumio[3496]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Jun 16 15:08:37 rivo volumio[3496]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Jun 16 15:08:37 rivo volumio[3496]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Jun 16 15:08:37 rivo volumio[3496]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jun 16 15:08:37 rivo volumio[3496]: at processTicksAndRejections (internal/process/task_queues.js:77:11) { Jun 16 15:08:37 rivo volumio[3496]: code: 'EADDRINUSE', Jun 16 15:08:37 rivo volumio[3496]: errno: -98, Jun 16 15:08:37 rivo volumio[3496]: syscall: 'listen', Jun 16 15:08:37 rivo volumio[3496]: address: '::', Jun 16 15:08:37 rivo volumio[3496]: port: 6599 Jun 16 15:08:37 rivo volumio[3496]: } Jun 16 15:08:37 rivo volumio[3496]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 16 15:08:38 rivo sudo[17413]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-16 15:07 Jun 16 15:08:38 rivo sudo[17413]: 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="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 10 Jun 2025 06:01:16 PM CEST" VOLUMIO_VERSION="3.816" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="5a6f819282ea0c6f84bf87456dce95cb"