-- Logs begin at Thu 2019-02-14 12:11:58 EET, end at Sat 2026-04-11 19:32:47 EEST. -- Apr 11 19:31:00 myvolumio volumio[823]: info: Starting Streaming Service Transparent Proxy Apr 11 19:31:00 myvolumio volumio[823]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 11 19:31:00 myvolumio volumio[823]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 11 19:31:00 myvolumio volumio[823]: info: Streaming services startup Apr 11 19:31:00 myvolumio volumio[823]: info: Starting Streaming Daemon Apr 11 19:31:00 myvolumio sudo[1326]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 11 19:31:00 myvolumio sudo[1326]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 19:31:00 myvolumio volumio[823]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 11 19:31:00 myvolumio sudo[1326]: pam_unix(sudo:session): session closed for user root Apr 11 19:31:00 myvolumio volumio[823]: error: Cannot start Volumio Streaming Daemon Apr 11 19:31:00 myvolumio volumio[823]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 11 19:31:00 myvolumio volumio[823]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 11 19:31:00 myvolumio volumio[823]: error: MyVolumio Custom Token format not valid, refreshing it Apr 11 19:31:00 myvolumio volumio[823]: STREAMING PROXY: Starting server on port 3245 Apr 11 19:31:00 myvolumio volumio[823]: Node JS runtime: 14 Apr 11 19:31:02 myvolumio volumio[823]: info: MyVolumio login type: Token Apr 11 19:31:02 myvolumio volumio[823]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 11 19:31:03 myvolumio volumio[823]: info: MyVolumio token set successfully Apr 11 19:31:03 myvolumio volumio[823]: info: MYVOLUMIO: Adding device Apr 11 19:31:03 myvolumio volumio[823]: info: MYVOLUMIO: Evaluating Server Apr 11 19:31:03 myvolumio volumio[823]: info: MyVolumio Plan changed: premium Apr 11 19:31:03 myvolumio volumio[823]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Apr 11 19:31:03 myvolumio volumio[823]: info: Removing browser output: myVolumio user plan is not superstar Apr 11 19:31:03 myvolumio volumio[823]: info: Removing audio output: Apr 11 19:31:03 myvolumio volumio[823]: info: MYVOLUMIO: Adding device Apr 11 19:31:03 myvolumio volumio[823]: info: MYVOLUMIO: Evaluating Server Apr 11 19:31:03 myvolumio volumio[823]: info: Remote config written successfully Apr 11 19:31:03 myvolumio volumio[823]: info: Starting Tunnel 1 Apr 11 19:31:03 myvolumio volumio[823]: info: Starting Tunnel Connection Checker Apr 11 19:31:03 myvolumio volumio[823]: info: Completed starting MyVolumio Plugin Apr 11 19:31:04 myvolumio volumio[823]: info: MYVolumio Device enabled Apr 11 19:31:04 myvolumio volumio[823]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Apr 11 19:31:04 myvolumio volumio[823]: info: MyVolumio status changed Apr 11 19:31:04 myvolumio volumio[823]: info: Streaming services startup Apr 11 19:31:04 myvolumio volumio[823]: info: Starting Streaming Daemon Apr 11 19:31:04 myvolumio sudo[1389]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 11 19:31:04 myvolumio sudo[1389]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 19:31:04 myvolumio volumio[823]: info: Setting Geolocation for MyVolumio to eu4 Apr 11 19:31:04 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 19:31:04 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 19:31:04 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 19:31:04 myvolumio sudo[1389]: pam_unix(sudo:session): session closed for user root Apr 11 19:31:04 myvolumio volumio[823]: error: Cannot start Volumio Streaming Daemon Apr 11 19:31:04 myvolumio volumio[823]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 11 19:31:04 myvolumio volumio[823]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 11 19:31:04 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Apr 11 19:31:04 myvolumio volumio[823]: error: [MyVolumio PluginManager] Cache data is invalid! Apr 11 19:31:04 myvolumio volumio[823]: info: Setting Geolocation for MyVolumio to eu11 Apr 11 19:31:04 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 19:31:04 myvolumio volumio[823]: info: Successfully Added MyVolumio device Apr 11 19:31:04 myvolumio volumio[823]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Apr 11 19:31:04 myvolumio volumio[823]: info: [1775925064921] Starting BluetoothController Apr 11 19:31:04 myvolumio volumio[823]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Apr 11 19:31:06 myvolumio volumio[823]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Apr 11 19:31:06 myvolumio sudo[1392]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Apr 11 19:31:06 myvolumio sudo[1392]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 19:31:06 myvolumio sudo[1392]: pam_unix(sudo:session): session closed for user root Apr 11 19:31:06 myvolumio volumio[823]: info: MRS: MultiRoom plugin initialized Apr 11 19:31:06 myvolumio volumio[823]: info: MRS: STOPPING SNAPCLIENT Apr 11 19:31:06 myvolumio volumio[823]: info: MRS: Snap server stop Apr 11 19:31:06 myvolumio sudo[1408]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Apr 11 19:31:06 myvolumio sudo[1408]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 19:31:06 myvolumio volumio[823]: info: MRS: STOPPING volumioStreaming Apr 11 19:31:06 myvolumio sudo[1410]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Apr 11 19:31:06 myvolumio sudo[1410]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 19:31:06 myvolumio sudo[1414]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Apr 11 19:31:06 myvolumio sudo[1414]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 19:31:06 myvolumio sudo[1410]: pam_unix(sudo:session): session closed for user root Apr 11 19:31:06 myvolumio sudo[1408]: pam_unix(sudo:session): session closed for user root Apr 11 19:31:06 myvolumio volumio[823]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Apr 11 19:31:06 myvolumio sudo[1414]: pam_unix(sudo:session): session closed for user root Apr 11 19:31:06 myvolumio sudo[1417]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Apr 11 19:31:06 myvolumio sudo[1417]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 19:31:06 myvolumio sudo[1417]: pam_unix(sudo:session): session closed for user root Apr 11 19:31:06 myvolumio volumio[823]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Apr 11 19:31:06 myvolumio volumio[823]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Apr 11 19:31:06 myvolumio volumio[823]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Apr 11 19:31:06 myvolumio volumio[823]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Apr 11 19:31:06 myvolumio volumio[823]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Apr 11 19:31:06 myvolumio volumio[823]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Apr 11 19:31:06 myvolumio volumio[823]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Apr 11 19:31:06 myvolumio volumio[823]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Apr 11 19:31:06 myvolumio volumio[823]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Apr 11 19:31:06 myvolumio volumio[823]: info: Preparing to generate the ALSA configuration file Apr 11 19:31:06 myvolumio volumio[823]: info: Updating MyVolumio device info Apr 11 19:31:06 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 19:31:06 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 19:31:06 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 19:31:06 myvolumio volumio[823]: info: Updating MyVolumio device info Apr 11 19:31:06 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 19:31:06 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 19:31:06 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 19:31:06 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Apr 11 19:31:06 myvolumio volumio[823]: info: Successfully Added MyVolumio device Apr 11 19:31:06 myvolumio volumio[823]: info: MRS: Removed streaming files Apr 11 19:31:06 myvolumio volumio[823]: info: MRS: volumioStreaming STOPPED Apr 11 19:31:06 myvolumio volumio[823]: info: MRS: SNAPSERVER STOPPED Apr 11 19:31:06 myvolumio volumio[823]: info: MRS: SNAPCLIENT STOPPED Apr 11 19:31:06 myvolumio volumio[823]: info: Asound.conf file unchanged, so no further update is needed Apr 11 19:31:06 myvolumio volumio[823]: info: Output device has changed, restarting MPD Apr 11 19:31:06 myvolumio systemd[1]: systemd-fsckd.service: Succeeded. Apr 11 19:31:06 myvolumio sudo[1420]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 11 19:31:06 myvolumio sudo[1420]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 19:31:06 myvolumio volumio[823]: info: Output device has changed, restarting Shairport Sync Apr 11 19:31:06 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 19:31:06 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 19:31:06 myvolumio sudo[1420]: pam_unix(sudo:session): session closed for user root Apr 11 19:31:06 myvolumio sudo[1423]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 11 19:31:06 myvolumio sudo[1423]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 19:31:06 myvolumio systemd[1]: Stopping Music Player Daemon... Apr 11 19:31:06 myvolumio volumio[823]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 11 19:31:06 myvolumio volumio[823]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 11 19:31:06 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 19:31:06 myvolumio volumio[823]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Apr 11 19:31:06 myvolumio volumio[823]: info: [MyVolumio PluginManager] Plugin bluetooth disabled by user. Not starting Apr 11 19:31:06 myvolumio volumio[823]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Apr 11 19:31:06 myvolumio volumio[823]: info: [MyVolumio PluginManager] Plugin multiroom disabled by user. Not starting Apr 11 19:31:06 myvolumio volumio[823]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Apr 11 19:31:06 myvolumio volumio[823]: info: [MyVolumio PluginManager] Plugin metavolumio disabled by user. Not starting Apr 11 19:31:06 myvolumio volumio[823]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Apr 11 19:31:06 myvolumio volumio[823]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Apr 11 19:31:06 myvolumio volumio[823]: info: [MyVolumio PluginManager] Plugin cd_controller disabled by user. Not starting Apr 11 19:31:06 myvolumio volumio[823]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Apr 11 19:31:06 myvolumio volumio[823]: info: Adding inputs REST Endpoints Apr 11 19:31:06 myvolumio volumio[823]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Apr 11 19:31:06 myvolumio volumio[823]: info: Scanning Audio Inputs Apr 11 19:31:06 myvolumio systemd[1]: mpd.service: Succeeded. Apr 11 19:31:06 myvolumio systemd[1]: Stopped Music Player Daemon. Apr 11 19:31:06 myvolumio volumio[823]: info: Checking against Known Cards name Apr 11 19:31:06 myvolumio volumio[823]: info: Adding Server instance for streaming Apr 11 19:31:06 myvolumio volumio[823]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Apr 11 19:31:06 myvolumio volumio[823]: error: Hi Res Audio Failed Login: Missing Login Data Apr 11 19:31:06 myvolumio volumio[823]: info: Adding HIGHRESAUDIO REST API Endpoints Apr 11 19:31:06 myvolumio volumio[823]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Apr 11 19:31:06 myvolumio volumio[823]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Apr 11 19:31:06 myvolumio volumio[823]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Apr 11 19:31:06 myvolumio volumio[823]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Apr 11 19:31:06 myvolumio volumio[823]: info: Refreshing QOBUZ token Apr 11 19:31:06 myvolumio volumio[823]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Apr 11 19:31:06 myvolumio volumio[823]: info: [MyVolumio PluginManager] Plugin tidalconnect disabled by user. Not starting Apr 11 19:31:06 myvolumio volumio[823]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Apr 11 19:31:06 myvolumio volumio[823]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Apr 11 19:31:06 myvolumio volumio[823]: info: QobuzConnect: Starting Qobuz Connect socket and service Apr 11 19:31:06 myvolumio systemd[1]: Starting Music Player Daemon... Apr 11 19:31:06 myvolumio volumio[823]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Apr 11 19:31:06 myvolumio volumio[823]: info: Adding TIDAL REST API Endpoints Apr 11 19:31:06 myvolumio volumio[823]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Apr 11 19:31:06 myvolumio sudo[1437]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Apr 11 19:31:06 myvolumio sudo[1437]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 19:31:06 myvolumio volumio[823]: info: MPD Permissions set Apr 11 19:31:06 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 19:31:06 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 19:31:06 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 19:31:06 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 19:31:06 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 19:31:06 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 19:31:06 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 19:31:06 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 19:31:06 myvolumio sudo[1437]: pam_unix(sudo:session): session closed for user root Apr 11 19:31:06 myvolumio sudo[1443]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Apr 11 19:31:06 myvolumio sudo[1443]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 19:31:06 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 19:31:06 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 19:31:06 myvolumio volumio[823]: info: Starting Shairport Sync Apr 11 19:31:06 myvolumio sudo[1432]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 11 19:31:06 myvolumio sudo[1432]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 19:31:06 myvolumio sudo[1432]: pam_unix(sudo:session): session closed for user root Apr 11 19:31:06 myvolumio systemd[1]: Started Volumio Qobuz Connect Service. Apr 11 19:31:06 myvolumio sudo[1443]: pam_unix(sudo:session): session closed for user root Apr 11 19:31:06 myvolumio sudo[1448]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 11 19:31:06 myvolumio sudo[1448]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 19:31:06 myvolumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 11 19:31:06 myvolumio systemd[1]: shairport-sync.service: Succeeded. Apr 11 19:31:06 myvolumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 11 19:31:06 myvolumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 11 19:31:06 myvolumio sudo[1448]: pam_unix(sudo:session): session closed for user root Apr 11 19:31:06 myvolumio volumio[823]: info: Shairport-Sync Started Apr 11 19:31:07 myvolumio volumio[823]: info: Executing endpoint qc_getconfig Apr 11 19:31:07 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Apr 11 19:31:07 myvolumio qobuz-connect[1447]: 20260411 19:31:07.051 [1447.1447] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Apr 11 19:31:07 myvolumio volumio[823]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Apr 11 19:31:07 myvolumio volumio[823]: info: QobuzConnect: QOBUZ Connect daemon connected Apr 11 19:31:07 myvolumio qobuz-connect[1447]: 20260411 19:31:07.140 [1447.1447] INFO VolumeManager: [0x1c4b540]: Setting new playback volume: 75 Apr 11 19:31:07 myvolumio qobuz-connect[1447]: 20260411 19:31:07.140 [1447.1447] INFO VolumeManager: [0x1c4b540]: Setting new mute state: 0 Apr 11 19:31:07 myvolumio qobuz-connect[1447]: 20260411 19:31:07.140 [1447.1447] INFO AudioStreamManager: [0x1c4b298]: Setting new audio download buffer size: 1048576 Apr 11 19:31:07 myvolumio qobuz-connect[1447]: 20260411 19:31:07.140 [1447.1447] INFO QobuzConnect: [0x1c4be08]: Client initialized! Apr 11 19:31:07 myvolumio qobuz-connect[1447]: 20260411 19:31:07.140 [1447.1447] INFO SampleApp: Starting Avahi advertising, name: MyVolumio, service name: _qobuz-connect._tcp Apr 11 19:31:07 myvolumio qobuz-connect[1447]: 20260411 19:31:07.147 [1447.1447] INFO LocalConfigManager: [0x1c4afc0]: Starting Local Configuration server Apr 11 19:31:07 myvolumio qobuz-connect[1447]: 20260411 19:31:07.148 [1447.1447] INFO SampleApp: Starting Local configuration server Apr 11 19:31:07 myvolumio qobuz-connect[1447]: 20260411 19:31:07.148 [1447.1447] INFO SampleApp: Connected to UNIX socket client 0x1c40f60 Apr 11 19:31:07 myvolumio volumio[823]: info: Successfully Updated MyVolumio device Apr 11 19:31:07 myvolumio volumio[823]: info: Access Token successfully retrieved Apr 11 19:31:07 myvolumio volumio[823]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 11 19:31:07 myvolumio volumio[823]: info: [1775925067168] CoreMusicLibrary::Adding element QOBUZ Apr 11 19:31:07 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 19:31:07 myvolumio volumio[823]: Cannot find translation for source QOBUZ Apr 11 19:31:07 myvolumio volumio[823]: info: Stopping AccessToken refresher cron for QOBUZ Apr 11 19:31:07 myvolumio volumio[823]: info: AccessToken refresher cron started for QOBUZ Apr 11 19:31:07 myvolumio qobuz-connect[1447]: 20260411 19:31:07.202 [1447.1447] INFO SampleApp: Playback volume changed: 75 Apr 11 19:31:07 myvolumio volumio[823]: info: Adding QOBUZ REST API Endpoints Apr 11 19:31:07 myvolumio volumio[823]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Apr 11 19:31:07 myvolumio volumio[823]: [Metrics] CommandRouter: 25s 954.05ms Apr 11 19:31:07 myvolumio volumio[823]: info: CoreCommandRouter::volumiosetStartupVolume Apr 11 19:31:07 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 19:31:07 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 19:31:07 myvolumio volumio[823]: info: CoreCommandRouter::Close All Modals sent Apr 11 19:31:07 myvolumio volumio[823]: info: CoreCommandRouter::Close All Modals sent Apr 11 19:31:07 myvolumio volumio[823]: info: CoreCommandRouter::volumioGetState Apr 11 19:31:07 myvolumio volumio[823]: info: CorePlayQueue::getTrack 0 Apr 11 19:31:07 myvolumio volumio[823]: info: Successfully Updated MyVolumio device Apr 11 19:31:07 myvolumio mpd[1449]: Apr 11 19:31 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 11 19:31:07 myvolumio systemd[1]: Started Music Player Daemon. Apr 11 19:31:07 myvolumio sudo[1423]: pam_unix(sudo:session): session closed for user root Apr 11 19:31:07 myvolumio volumio[823]: error: updateQueue error: null Apr 11 19:31:08 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Apr 11 19:31:08 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 19:31:08 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Apr 11 19:31:08 myvolumio sudo[1469]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Apr 11 19:31:08 myvolumio sudo[1469]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 19:31:08 myvolumio systemd[1]: Started MyVolumio SSH Tunnel. Apr 11 19:31:08 myvolumio sudo[1469]: pam_unix(sudo:session): session closed for user root Apr 11 19:31:08 myvolumio volumio[823]: info: Remote SSH Started Apr 11 19:31:08 myvolumio autossh[1472]: port set to 0, monitoring disabled Apr 11 19:31:08 myvolumio autossh[1472]: starting ssh (count 1) Apr 11 19:31:08 myvolumio autossh[1472]: ssh child pid is 1475 Apr 11 19:31:09 myvolumio volumio[823]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Apr 11 19:31:09 myvolumio volumio[823]: info: CoreCommandRouter::volumioGetState Apr 11 19:31:09 myvolumio volumio[823]: info: CorePlayQueue::getTrack 0 Apr 11 19:31:09 myvolumio volumiossh-tunnel[1471]: Warning: Permanently added '[eu11.myvolumio.org]:2222,[64.226.87.15]:2222' (ED25519) to the list of known hosts. Apr 11 19:31:12 myvolumio kernel: xhci_hcd 0000:01:00.0: ERROR Transfer event for disabled endpoint slot 2 ep 1 Apr 11 19:31:12 myvolumio kernel: xhci_hcd 0000:01:00.0: @0000000429516760 00000000 00000000 0e000000 02028000 Apr 11 19:31:14 myvolumio volumio[823]: info: BOOT COMPLETED Apr 11 19:31:14 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 11 19:31:14 myvolumio volumio[823]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Apr 11 19:31:14 myvolumio volumio[823]: info: CoreCommandRouter::volumioGetState Apr 11 19:31:14 myvolumio volumio[823]: info: CorePlayQueue::getTrack 0 Apr 11 19:31:16 myvolumio volumio[1300]: ........................................................................................................................................................................................................................++++ Apr 11 19:31:16 myvolumio volumio[1300]: e is 65537 (0x010001) Apr 11 19:31:16 myvolumio volumio[1300]: writing RSA key Apr 11 19:31:16 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 19:31:16 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 19:31:16 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 11 19:31:16 myvolumio volumio-remote-updater[596]: No test mode Apr 11 19:31:16 myvolumio volumio-remote-updater[596]: No alpha test mode Apr 11 19:31:16 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Apr 11 19:31:17 myvolumio volumio[823]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Apr 11 19:31:17 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 11 19:31:18 myvolumio systemd[1]: systemd-timedated.service: Succeeded. Apr 11 19:31:19 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 19:31:19 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 19:31:19 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Apr 11 19:31:19 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Apr 11 19:31:19 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 11 19:31:19 myvolumio volumio[823]: info: CoreCommandRouter::volumioGetBrowseSources Apr 11 19:31:19 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 19:31:19 myvolumio go-librespot[1058]: time="2026-04-11T19:31:19+03:00" level=trace msg="sent dealer ping" Apr 11 19:31:19 myvolumio go-librespot[1058]: time="2026-04-11T19:31:19+03:00" level=trace msg="received dealer pong" Apr 11 19:31:45 myvolumio ntpd[776]: Soliciting pool server 194.54.80.29 Apr 11 19:31:45 myvolumio ntpd[776]: Soliciting pool server 217.12.206.12 Apr 11 19:31:46 myvolumio ntpd[776]: Soliciting pool server 162.159.200.1 Apr 11 19:31:46 myvolumio ntpd[776]: Soliciting pool server 176.120.61.236 Apr 11 19:31:46 myvolumio ntpd[776]: Soliciting pool server 91.231.182.17 Apr 11 19:31:47 myvolumio ntpd[776]: Soliciting pool server 31.133.97.13 Apr 11 19:31:47 myvolumio ntpd[776]: Soliciting pool server 62.149.0.30 Apr 11 19:31:48 myvolumio ntpd[776]: Soliciting pool server 194.8.146.38 Apr 11 19:31:48 myvolumio ntpd[776]: Soliciting pool server 213.231.2.124 Apr 11 19:31:48 myvolumio ntpd[776]: Soliciting pool server 188.191.239.24 Apr 11 19:31:48 myvolumio ntpd[776]: Soliciting pool server 162.159.200.123 Apr 11 19:31:48 myvolumio ntpd[776]: Soliciting pool server 62.149.2.7 Apr 11 19:31:49 myvolumio go-librespot[1058]: time="2026-04-11T19:31:49+03:00" level=trace msg="sent dealer ping" Apr 11 19:31:49 myvolumio go-librespot[1058]: time="2026-04-11T19:31:49+03:00" level=trace msg="received dealer pong" Apr 11 19:31:49 myvolumio ntpd[776]: Soliciting pool server 91.236.251.34 Apr 11 19:31:49 myvolumio ntpd[776]: Soliciting pool server 109.86.186.61 Apr 11 19:31:50 myvolumio ntpd[776]: Soliciting pool server 91.236.251.14 Apr 11 19:31:50 myvolumio ntpd[776]: Soliciting pool server 91.236.251.29 Apr 11 19:31:51 myvolumio ntpd[776]: Soliciting pool server 2a02:c6c1:c:207::13 Apr 11 19:31:54 myvolumio ntpd[776]: receive: Unexpected origin timestamp 0xed84f5f8.eba77823 does not match aorg 0000000000.00000000 from server@162.159.200.1 xmt 0xed84f5fa.14124ec8 Apr 11 19:31:54 myvolumio ntpd[776]: receive: Unexpected origin timestamp 0xed84f5f8.eba66a8e does not match aorg 0000000000.00000000 from server@31.133.97.13 xmt 0xed84f5fa.14378063 Apr 11 19:31:54 myvolumio ntpd[776]: receive: Unexpected origin timestamp 0xed84f5f8.eba23081 does not match aorg 0000000000.00000000 from server@188.191.239.24 xmt 0xed84f5fa.161a9329 Apr 11 19:31:54 myvolumio ntpd[776]: receive: Unexpected origin timestamp 0xed84f5f8.eba4cb88 does not match aorg 0000000000.00000000 from server@213.231.2.124 xmt 0xed84f5fa.15426740 Apr 11 19:31:54 myvolumio ntpd[776]: receive: Unexpected origin timestamp 0xed84f5f8.eba85ac6 does not match aorg 0000000000.00000000 from server@217.12.206.12 xmt 0xed84f5fa.1af26288 Apr 11 19:32:20 myvolumio go-librespot[1058]: time="2026-04-11T19:32:20+03:00" level=trace msg="sent dealer ping" Apr 11 19:32:20 myvolumio go-librespot[1058]: time="2026-04-11T19:32:20+03:00" level=trace msg="received dealer pong" Apr 11 19:32:28 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:28.174+03:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.2.117:48984 Apr 11 19:32:28 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:28.223+03:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.2.117:48984 @ 0x2001650" latency=125.459402ms timeout=10s Apr 11 19:32:28 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:28.225+03:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" Apr 11 19:32:28 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:28.225+03:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.2.117:48984 @ 0x2001650" latency=126.419265ms platform=PLATFORM_ANDROID version=5.260331.0 Apr 11 19:32:28 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 11 19:32:28 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 11 19:32:28 myvolumio volumio[823]: info: Received Get System Info Apr 11 19:32:28 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 19:32:28 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 19:32:28 myvolumio volumio[823]: info: Discovery: Getting this device information Apr 11 19:32:28 myvolumio volumio[823]: info: CoreCommandRouter::volumioGetState Apr 11 19:32:28 myvolumio volumio[823]: info: CorePlayQueue::getTrack 0 Apr 11 19:32:28 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 19:32:28 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:28.232+03:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" name=MyVolumio Apr 11 19:32:28 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:28.235+03:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" language=en Apr 11 19:32:28 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Apr 11 19:32:28 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:28.237+03:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" timezone=Europe/Kiev Apr 11 19:32:28 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:28.238+03:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" available=true connected=true macAddress=dc:a6:32:64:ae:c8 ip4Address=192.168.2.56/24 ip6Address= Apr 11 19:32:28 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:28.240+03:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Apr 11 19:32:28 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:28.240+03:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" setupComplete=true Apr 11 19:32:28 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Apr 11 19:32:28 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 11 19:32:28 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 19:32:28 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 19:32:28 myvolumio volumio[823]: amixer -c 0 info | grep "bcm2835 ALSA" Apr 11 19:32:28 myvolumio volumio[823]: amixer -c 1 info | grep "bcm2835 Headphones" Apr 11 19:32:28 myvolumio volumio[823]: Card hw:1 'Headphones'/'bcm2835 Headphones' Apr 11 19:32:28 myvolumio volumio[823]: amixer -c 5 info | grep "AudioQuest DragonFly Cobalt v1." Apr 11 19:32:28 myvolumio volumio[823]: Card hw:5 'v1'/'AudioQuest AudioQuest DragonFly Cobalt v1. at usb-0000:01:00.0-1.2, full speed' Apr 11 19:32:28 myvolumio volumio[823]: amixer -c 5 info | grep "AudioQuest DragonFly Cobalt v1." Apr 11 19:32:28 myvolumio volumio[823]: Card hw:5 'v1'/'AudioQuest AudioQuest DragonFly Cobalt v1. at usb-0000:01:00.0-1.2, full speed' Apr 11 19:32:28 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:28.514+03:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" selectedOutputId=5 Apr 11 19:32:28 myvolumio volumio[823]: info: Received Get System Info Apr 11 19:32:28 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 19:32:28 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 19:32:28 myvolumio volumio[823]: info: Discovery: Getting this device information Apr 11 19:32:28 myvolumio volumio[823]: info: CoreCommandRouter::volumioGetState Apr 11 19:32:28 myvolumio volumio[823]: info: CorePlayQueue::getTrack 0 Apr 11 19:32:28 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 19:32:28 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:28.604+03:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" currentVersion=3.912 latestVersion=3.912 Apr 11 19:32:28 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:28.604+03:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.2.117:48984 @ 0x2001650" status=UPDATE_STATUS_NONE progress=0 Apr 11 19:32:28 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:28.604+03:00 level=INFO msg="emitting user changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" userId= Apr 11 19:32:28 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:28.605+03:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" providers=3 Apr 11 19:32:28 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 11 19:32:28 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 11 19:32:28 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 11 19:32:28 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 19:32:28 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 19:32:28 myvolumio volumio[823]: info: Discovery: Getting this device information Apr 11 19:32:28 myvolumio volumio[823]: info: CoreCommandRouter::volumioGetState Apr 11 19:32:28 myvolumio volumio[823]: info: CorePlayQueue::getTrack 0 Apr 11 19:32:28 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 19:32:28 myvolumio volumio[823]: verbose: New Socket.io Connection to 192.168.2.56:3000 from 192.168.2.117 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Apr 11 19:32:29 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 11 19:32:29 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 11 19:32:29 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:29.984+03:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.2.117:48984 @ 0x2001650" latency=223.512114ms timeout=10s Apr 11 19:32:29 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:29.984+03:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" Apr 11 19:32:29 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:29.984+03:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.2.117:48984 @ 0x2001650" latency=223.508336ms platform=PLATFORM_ANDROID version=5.260331.0 Apr 11 19:32:29 myvolumio volumio[823]: info: Received Get System Info Apr 11 19:32:29 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 19:32:29 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 19:32:29 myvolumio volumio[823]: info: Discovery: Getting this device information Apr 11 19:32:29 myvolumio volumio[823]: info: CoreCommandRouter::volumioGetState Apr 11 19:32:29 myvolumio volumio[823]: info: CorePlayQueue::getTrack 0 Apr 11 19:32:29 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 19:32:29 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:29.988+03:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" name=MyVolumio Apr 11 19:32:29 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:29.989+03:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" language=en Apr 11 19:32:29 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Apr 11 19:32:29 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:29.991+03:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" timezone=Europe/Kiev Apr 11 19:32:29 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:29.992+03:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" available=true connected=true macAddress=dc:a6:32:64:ae:c8 ip4Address=192.168.2.56/24 ip6Address= Apr 11 19:32:29 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:29.993+03:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Apr 11 19:32:29 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:29.993+03:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" setupComplete=true Apr 11 19:32:29 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Apr 11 19:32:30 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 11 19:32:30 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 19:32:30 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 19:32:30 myvolumio volumio[823]: amixer -c 0 info | grep "bcm2835 ALSA" Apr 11 19:32:30 myvolumio volumio[823]: amixer -c 1 info | grep "bcm2835 Headphones" Apr 11 19:32:30 myvolumio volumio[823]: Card hw:1 'Headphones'/'bcm2835 Headphones' Apr 11 19:32:30 myvolumio volumio[823]: amixer -c 5 info | grep "AudioQuest DragonFly Cobalt v1." Apr 11 19:32:30 myvolumio volumio[823]: Card hw:5 'v1'/'AudioQuest AudioQuest DragonFly Cobalt v1. at usb-0000:01:00.0-1.2, full speed' Apr 11 19:32:30 myvolumio volumio[823]: amixer -c 5 info | grep "AudioQuest DragonFly Cobalt v1." Apr 11 19:32:30 myvolumio volumio[823]: Card hw:5 'v1'/'AudioQuest AudioQuest DragonFly Cobalt v1. at usb-0000:01:00.0-1.2, full speed' Apr 11 19:32:30 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:30.252+03:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" selectedOutputId=5 Apr 11 19:32:30 myvolumio volumio[823]: info: Received Get System Info Apr 11 19:32:30 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 19:32:30 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 19:32:30 myvolumio volumio[823]: info: Discovery: Getting this device information Apr 11 19:32:30 myvolumio volumio[823]: info: CoreCommandRouter::volumioGetState Apr 11 19:32:30 myvolumio volumio[823]: info: CorePlayQueue::getTrack 0 Apr 11 19:32:30 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 19:32:30 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:30.384+03:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" currentVersion=3.912 latestVersion=3.912 Apr 11 19:32:30 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:30.384+03:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.2.117:48984 @ 0x2001650" status=UPDATE_STATUS_NONE progress=0 Apr 11 19:32:30 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:30.384+03:00 level=INFO msg="emitting user changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" userId= Apr 11 19:32:30 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:30.384+03:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" providers=3 Apr 11 19:32:30 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:30.580+03:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" plugins=54 Apr 11 19:32:30 myvolumio volumio[823]: info: CoreCommandRouter::volumioGetState Apr 11 19:32:30 myvolumio volumio[823]: info: CorePlayQueue::getTrack 0 Apr 11 19:32:30 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:30.586+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" state=STATUS_STOPPED positionMs=0 volume=100 Apr 11 19:32:30 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:30.586+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" id=qobuz://song/334969897 title="The Invisible Gossamer Bridge" Apr 11 19:32:30 myvolumio volumio[823]: info: CoreCommandRouter::volumioGetState Apr 11 19:32:30 myvolumio volumio[823]: info: CorePlayQueue::getTrack 0 Apr 11 19:32:30 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:30.587+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" id=qobuz://song/334969897 title="The Invisible Gossamer Bridge" Apr 11 19:32:30 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:30.589+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" state=STATUS_STOPPED positionMs=0 volume=100 Apr 11 19:32:30 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:30.589+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" id=qobuz://song/334969897 title="The Invisible Gossamer Bridge" Apr 11 19:32:30 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:30.666+03:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.2.117:48984 @ 0x2001650" latency=126.056023ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Apr 11 19:32:31 myvolumio sudo[1733]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 11 19:32:31 myvolumio sudo[1733]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 19:32:31 myvolumio sudo[1733]: pam_unix(sudo:session): session closed for user root Apr 11 19:32:31 myvolumio sudo[1735]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 11 19:32:31 myvolumio sudo[1735]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 19:32:31 myvolumio sudo[1735]: pam_unix(sudo:session): session closed for user root Apr 11 19:32:31 myvolumio volumio[823]: verbose: New Socket.io Connection to 192.168.2.56 from 192.168.2.117 UA: Mozilla/5.0 (Linux; Android 16; SM-F956B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/147.0.7727.55 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Apr 11 19:32:31 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 11 19:32:31 myvolumio volumio[823]: info: CoreCommandRouter::volumioGetVisibleSources Apr 11 19:32:31 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 19:32:31 myvolumio volumio[823]: info: CoreCommandRouter::volumioGetState Apr 11 19:32:31 myvolumio volumio[823]: info: CorePlayQueue::getTrack 0 Apr 11 19:32:31 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 11 19:32:31 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 11 19:32:31 myvolumio volumio[823]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Apr 11 19:32:31 myvolumio volumio[823]: info: Received Get System Info Apr 11 19:32:31 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 19:32:31 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 19:32:31 myvolumio volumio[823]: info: Discovery: Getting this device information Apr 11 19:32:31 myvolumio volumio[823]: info: CoreCommandRouter::volumioGetState Apr 11 19:32:31 myvolumio volumio[823]: info: CorePlayQueue::getTrack 0 Apr 11 19:32:31 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 19:32:31 myvolumio volumio[823]: info: CoreCommandRouter::volumioGetState Apr 11 19:32:31 myvolumio volumio[823]: info: CorePlayQueue::getTrack 0 Apr 11 19:32:31 myvolumio volumio[823]: info: Listing playlists Apr 11 19:32:31 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 11 19:32:31 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 11 19:32:31 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 11 19:32:31 myvolumio sudo[1739]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 11 19:32:31 myvolumio sudo[1739]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 19:32:31 myvolumio sudo[1739]: pam_unix(sudo:session): session closed for user root Apr 11 19:32:31 myvolumio sudo[1742]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 11 19:32:31 myvolumio sudo[1742]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 19:32:31 myvolumio sudo[1742]: pam_unix(sudo:session): session closed for user root Apr 11 19:32:31 myvolumio volumio[823]: verbose: New Socket.io Connection to 192.168.2.56 from 192.168.2.117 UA: Mozilla/5.0 (Linux; Android 16; SM-F956B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/147.0.7727.55 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Apr 11 19:32:31 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 11 19:32:31 myvolumio volumio[823]: info: CoreCommandRouter::volumioGetVisibleSources Apr 11 19:32:31 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 19:32:31 myvolumio volumio[823]: info: CoreCommandRouter::volumioGetState Apr 11 19:32:31 myvolumio volumio[823]: info: CorePlayQueue::getTrack 0 Apr 11 19:32:31 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 11 19:32:31 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 11 19:32:31 myvolumio volumio[823]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Apr 11 19:32:31 myvolumio volumio[823]: info: Received Get System Info Apr 11 19:32:31 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 19:32:31 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 19:32:31 myvolumio volumio[823]: info: Discovery: Getting this device information Apr 11 19:32:31 myvolumio volumio[823]: info: CoreCommandRouter::volumioGetState Apr 11 19:32:31 myvolumio volumio[823]: info: CorePlayQueue::getTrack 0 Apr 11 19:32:31 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 19:32:31 myvolumio volumio[823]: info: CoreCommandRouter::volumioGetState Apr 11 19:32:31 myvolumio volumio[823]: info: CorePlayQueue::getTrack 0 Apr 11 19:32:31 myvolumio volumio[823]: info: Listing playlists Apr 11 19:32:31 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 11 19:32:31 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 11 19:32:32 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 11 19:32:33 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Apr 11 19:32:33 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 11 19:32:33 myvolumio volumio[823]: info: Received Get System Info Apr 11 19:32:33 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 19:32:33 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 19:32:33 myvolumio volumio[823]: info: Discovery: Getting this device information Apr 11 19:32:33 myvolumio volumio[823]: info: CoreCommandRouter::volumioGetState Apr 11 19:32:33 myvolumio volumio[823]: info: CorePlayQueue::getTrack 0 Apr 11 19:32:33 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 19:32:34 myvolumio volumio[823]: info: CoreCommandRouter::volumioPlay Apr 11 19:32:34 myvolumio volumio[823]: info: CoreStateMachine::play index undefined Apr 11 19:32:34 myvolumio volumio[823]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 19:32:34 myvolumio volumio[823]: info: CorePlayQueue::getTrack 0 Apr 11 19:32:34 myvolumio volumio[823]: info: CoreStateMachine::startPlaybackTimer Apr 11 19:32:34 myvolumio volumio[823]: info: CorePlayQueue::getTrack 0 Apr 11 19:32:34 myvolumio volumio[823]: info: [1775925154480] ControllerQobuz::clearAddPlayTrack Apr 11 19:32:34 myvolumio volumio[823]: verbose: ControllerMpd::sendMpdCommand stop Apr 11 19:32:34 myvolumio volumio[823]: info: sendMpdCommand stop took 1 milliseconds Apr 11 19:32:34 myvolumio volumio[823]: verbose: ControllerMpd::sendMpdCommand clear Apr 11 19:32:34 myvolumio volumio[823]: info: Apr 11 19:32:34 myvolumio volumio[823]: ---------------------------- MPD announces system playlist update Apr 11 19:32:34 myvolumio volumio[823]: info: Ignoring MPD Status Update Apr 11 19:32:34 myvolumio volumio[823]: info: sendMpdCommand clear took 5 milliseconds Apr 11 19:32:34 myvolumio volumio[823]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/334969897" Apr 11 19:32:34 myvolumio volumio[823]: error: updateQueue error: null Apr 11 19:32:34 myvolumio volumio[823]: info: ------------------------------ 6ms Apr 11 19:32:34 myvolumio volumio[823]: STREAMING PROXY: Handling url /?data=qobuz://song/334969897 Apr 11 19:32:34 myvolumio volumio[823]: info: Executing endpoint getStreamUrlqobuz Apr 11 19:32:34 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Apr 11 19:32:35 myvolumio volumio[823]: info: getStreamUrl took 660 milliseconds Apr 11 19:32:35 myvolumio volumio[823]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=1359829&eid=334969897&fmt=7&profile=raw&app_id=539451548&cid=1955574&etsp=1775928754&hmac=tk6tTL-34Xi74SHcYqt6b1HoIzo Apr 11 19:32:35 myvolumio volumio[823]: STREAMING PROXY: Requesting upstream with range: none Apr 11 19:32:35 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 11 19:32:35 myvolumio volumio[823]: info: Received Get System Info Apr 11 19:32:35 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 11 19:32:35 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 11 19:32:35 myvolumio volumio[823]: info: Discovery: Getting this device information Apr 11 19:32:35 myvolumio volumio[823]: info: CoreCommandRouter::volumioGetState Apr 11 19:32:35 myvolumio volumio[823]: info: CorePlayQueue::getTrack 0 Apr 11 19:32:35 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 11 19:32:35 myvolumio volumio[823]: STREAMING PROXY: Upstream status code: 200 Apr 11 19:32:35 myvolumio volumio[823]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/334969897" Apr 11 19:32:35 myvolumio volumio[823]: STREAMING PROXY: Client closed connection Apr 11 19:32:35 myvolumio volumio[823]: info: Apr 11 19:32:35 myvolumio volumio[823]: ---------------------------- MPD announces system playlist update Apr 11 19:32:35 myvolumio volumio[823]: info: Ignoring MPD Status Update Apr 11 19:32:35 myvolumio volumio[823]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/334969897" took 2 milliseconds Apr 11 19:32:35 myvolumio volumio[823]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 11 19:32:35 myvolumio volumio[823]: STREAMING PROXY: Upstream closed. Received 15276 bytes Apr 11 19:32:35 myvolumio volumio[823]: STREAMING PROXY: Incomplete transfer. Expected 65087168, got 15276 Apr 11 19:32:35 myvolumio volumio[823]: STREAMING PROXY: Retrying with range: bytes=15276- (attempt 1) Apr 11 19:32:35 myvolumio volumio[823]: verbose: ControllerMpd::sendMpdCommand play Apr 11 19:32:35 myvolumio volumio[823]: info: ------------------------------ 5ms Apr 11 19:32:35 myvolumio volumio[823]: STREAMING PROXY: Handling url /?data=qobuz://song/334969897 Apr 11 19:32:35 myvolumio volumio[823]: info: sendMpdCommand play took 3 milliseconds Apr 11 19:32:35 myvolumio volumio[823]: info: Executing endpoint getStreamUrlqobuz Apr 11 19:32:35 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Apr 11 19:32:36 myvolumio volumio[823]: info: getStreamUrl took 435 milliseconds Apr 11 19:32:36 myvolumio volumio[823]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=1359829&eid=334969897&fmt=7&profile=raw&app_id=539451548&cid=1955574&etsp=1775928756&hmac=qlgNPSHF6kuMcoXxm0pLHfhUtjM Apr 11 19:32:36 myvolumio volumio[823]: STREAMING PROXY: Requesting upstream with range: none Apr 11 19:32:36 myvolumio volumio[823]: STREAMING PROXY: Upstream status code: 200 Apr 11 19:32:36 myvolumio volumio[823]: info: Apr 11 19:32:36 myvolumio volumio[823]: ---------------------------- MPD announces state update: player Apr 11 19:32:36 myvolumio volumio[823]: info: ControllerMpd::getState Apr 11 19:32:36 myvolumio volumio[823]: verbose: ControllerMpd::sendMpdCommand status Apr 11 19:32:36 myvolumio volumio[823]: info: Apr 11 19:32:36 myvolumio volumio[823]: ---------------------------- MPD announces state update: player Apr 11 19:32:36 myvolumio volumio[823]: info: sendMpdCommand status took 16 milliseconds Apr 11 19:32:36 myvolumio volumio[823]: info: ControllerMpd::getState Apr 11 19:32:36 myvolumio volumio[823]: verbose: ControllerMpd::sendMpdCommand status Apr 11 19:32:36 myvolumio volumio[823]: verbose: ControllerMpd::parseState Apr 11 19:32:36 myvolumio volumio[823]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 19:32:36 myvolumio volumio[823]: info: sendMpdCommand status took 4 milliseconds Apr 11 19:32:36 myvolumio volumio[823]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 11 19:32:36 myvolumio volumio[823]: verbose: ControllerMpd::parseState Apr 11 19:32:36 myvolumio volumio[823]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 19:32:36 myvolumio volumio[823]: verbose: ControllerMpd::parseTrackInfo Apr 11 19:32:36 myvolumio volumio[823]: info: ControllerMpd::pushState Apr 11 19:32:36 myvolumio volumio[823]: info: CoreCommandRouter::servicePushState Apr 11 19:32:36 myvolumio volumio[823]: info: CorePlayQueue::getTrack 0 Apr 11 19:32:36 myvolumio volumio[823]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":306,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"334969897","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/334969897","trackType":"qobuz"} Apr 11 19:32:36 myvolumio volumio[823]: verbose: CURRENT POSITION 0 Apr 11 19:32:36 myvolumio volumio[823]: info: CoreStateMachine::syncState stateService play Apr 11 19:32:36 myvolumio volumio[823]: info: CoreStateMachine::syncState currentStatus stop Apr 11 19:32:36 myvolumio volumio[823]: info: ------------------------------ 32ms Apr 11 19:32:36 myvolumio volumio[823]: info: sendMpdCommand playlistinfo took 9 milliseconds Apr 11 19:32:36 myvolumio volumio[823]: verbose: ControllerMpd::parseTrackInfo Apr 11 19:32:36 myvolumio volumio[823]: info: ControllerMpd::pushState Apr 11 19:32:36 myvolumio volumio[823]: info: CoreCommandRouter::servicePushState Apr 11 19:32:36 myvolumio volumio[823]: info: CorePlayQueue::getTrack 0 Apr 11 19:32:36 myvolumio volumio[823]: verbose: STATE SERVICE {"status":"play","position":0,"seek":483,"duration":306,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1620 Kbps","isStreaming":false,"title":"334969897","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/334969897","trackType":"qobuz"} Apr 11 19:32:36 myvolumio volumio[823]: verbose: CURRENT POSITION 0 Apr 11 19:32:36 myvolumio volumio[823]: info: CoreStateMachine::syncState stateService play Apr 11 19:32:36 myvolumio volumio[823]: info: CoreStateMachine::syncState currentStatus play Apr 11 19:32:36 myvolumio volumio[823]: info: Received an update from plugin. extracting info from payload Apr 11 19:32:36 myvolumio volumio[823]: info: CoreStateMachine::pushState Apr 11 19:32:36 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 19:32:36 myvolumio volumio[823]: info: CoreCommandRouter::volumioPushState Apr 11 19:32:36 myvolumio volumio[823]: info: CoreCommandRouter::volumioGetState Apr 11 19:32:36 myvolumio volumio[823]: info: CoreStateMachine::pushState Apr 11 19:32:36 myvolumio volumio[823]: info: CoreCommandRouter::volumioPushState Apr 11 19:32:36 myvolumio volumio[823]: info: CoreCommandRouter::volumioGetState Apr 11 19:32:36 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:36.559+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" state=STATUS_PLAYING positionMs=0 volume=100 Apr 11 19:32:36 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:36.559+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" id=qobuz://song/334969897 title="The Invisible Gossamer Bridge" Apr 11 19:32:36 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:36.560+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" id=qobuz://song/334969897 title="The Invisible Gossamer Bridge" Apr 11 19:32:36 myvolumio volumio[823]: info: ------------------------------ 44ms Apr 11 19:32:36 myvolumio volumio[823]: STREAMING PROXY: Resuming with range: bytes=15276- Apr 11 19:32:37 myvolumio volumio[823]: STREAMING PROXY: Resume upstream status code: 206 Apr 11 19:32:38 myvolumio volumio[823]: info: CoreCommandRouter::volumioPause Apr 11 19:32:38 myvolumio volumio[823]: info: CoreStateMachine::pause Apr 11 19:32:38 myvolumio volumio[823]: info: CoreStateMachine::stPlaybackTimer Apr 11 19:32:38 myvolumio volumio[823]: info: CoreStateMachine::servicePause Apr 11 19:32:38 myvolumio volumio[823]: info: CorePlayQueue::getTrack 0 Apr 11 19:32:38 myvolumio volumio[823]: info: CoreCommandRouter::servicePause Apr 11 19:32:38 myvolumio volumio[823]: info: [1775925158671] ControllerQobuz::pause Apr 11 19:32:38 myvolumio volumio[823]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 11 19:32:38 myvolumio volumio[823]: info: ControllerMpd::pause Apr 11 19:32:38 myvolumio volumio[823]: verbose: ControllerMpd::sendMpdCommand pause Apr 11 19:32:38 myvolumio volumio[823]: info: Apr 11 19:32:38 myvolumio volumio[823]: ---------------------------- MPD announces state update: player Apr 11 19:32:38 myvolumio volumio[823]: info: sendMpdCommand pause took 2 milliseconds Apr 11 19:32:38 myvolumio volumio[823]: info: ControllerMpd::getState Apr 11 19:32:38 myvolumio volumio[823]: verbose: ControllerMpd::sendMpdCommand status Apr 11 19:32:38 myvolumio volumio[823]: info: sendMpdCommand status took 0 milliseconds Apr 11 19:32:38 myvolumio volumio[823]: verbose: ControllerMpd::parseState Apr 11 19:32:38 myvolumio volumio[823]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 19:32:38 myvolumio volumio[823]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 11 19:32:38 myvolumio volumio[823]: verbose: ControllerMpd::parseTrackInfo Apr 11 19:32:38 myvolumio volumio[823]: info: ControllerMpd::pushState Apr 11 19:32:38 myvolumio volumio[823]: info: CoreCommandRouter::servicePushState Apr 11 19:32:38 myvolumio volumio[823]: info: CorePlayQueue::getTrack 0 Apr 11 19:32:38 myvolumio volumio[823]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":3107,"duration":306,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1656 Kbps","isStreaming":false,"title":"334969897","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/334969897","trackType":"qobuz"} Apr 11 19:32:38 myvolumio volumio[823]: verbose: CURRENT POSITION 0 Apr 11 19:32:38 myvolumio volumio[823]: info: CoreStateMachine::syncState stateService pause Apr 11 19:32:38 myvolumio volumio[823]: info: CoreStateMachine::syncState currentStatus pause Apr 11 19:32:38 myvolumio volumio[823]: info: CoreStateMachine::pushState Apr 11 19:32:38 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 19:32:38 myvolumio volumio[823]: info: CoreCommandRouter::volumioPushState Apr 11 19:32:38 myvolumio volumio[823]: info: CoreCommandRouter::volumioGetState Apr 11 19:32:38 myvolumio volumio[823]: info: CoreStateMachine::stPlaybackTimer Apr 11 19:32:38 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:38.697+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" state=STATUS_PAUSED positionMs=2003 volume=100 Apr 11 19:32:38 myvolumio volumio5-onboarding[972]: time=2026-04-11T19:32:38.698+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.2.117:48984 @ 0x2001650" id=qobuz://song/334969897 title="The Invisible Gossamer Bridge" Apr 11 19:32:38 myvolumio volumio[823]: info: ------------------------------ 27ms Apr 11 19:32:41 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 11 19:32:43 myvolumio volumio[823]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 11 19:32:43 myvolumio volumio[823]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 11 19:32:43 myvolumio volumio[823]: info: Retrieving Cloud Streaming UI Apr 11 19:32:43 myvolumio volumio[823]: info: Getting Tidal Cloud Configuration Apr 11 19:32:43 myvolumio volumio[823]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 11 19:32:43 myvolumio volumio[823]: info: Getting Qobuz Cloud Configuration Apr 11 19:32:43 myvolumio volumio[823]: info: Asking plugin for UI Config Apr 11 19:32:43 myvolumio volumio[823]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 11 19:32:43 myvolumio volumio[823]: info: Getting Spotify Cloud Configuration Apr 11 19:32:43 myvolumio volumio[823]: info: Asking plugin for UI Config Apr 11 19:32:43 myvolumio volumio[823]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 11 19:32:43 myvolumio volumio[823]: info: Saving Spotify Acccount Apr 11 19:32:43 myvolumio volumio[823]: info: Got it Apr 11 19:32:43 myvolumio volumio[823]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Apr 11 19:32:43 myvolumio volumio[823]: info: Got Tidal Cloud Configuration Apr 11 19:32:43 myvolumio volumio[823]: info: Got it Apr 11 19:32:43 myvolumio volumio[823]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 11 19:32:43 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 11 19:32:43 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 11 19:32:43 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 11 19:32:43 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 11 19:32:43 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 19:32:43 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 19:32:43 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 19:32:43 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 11 19:32:43 myvolumio volumio[823]: info: CoreCommandRouter::volumioGetBrowseSources Apr 11 19:32:43 myvolumio volumio[823]: info: CoreCommandRouter::volumioGetBrowseSources Apr 11 19:32:43 myvolumio volumio[823]: info: CoreCommandRouter::volumioGetBrowseSources Apr 11 19:32:43 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 11 19:32:43 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Apr 11 19:32:45 myvolumio volumio[823]: info: Disabling MyMusic plugin upnp Apr 11 19:32:45 myvolumio sudo[1823]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Apr 11 19:32:45 myvolumio sudo[1823]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 11 19:32:45 myvolumio volumio[823]: error: Upnp client error: Error: This socket has been ended by the other party Apr 11 19:32:45 myvolumio systemd[1]: Stopping UPnP Renderer front-end to MPD... Apr 11 19:32:46 myvolumio volumio[823]: info: Enabling MyMusic plugin upnp Apr 11 19:32:46 myvolumio volumio[823]: info: Enabling plugin upnp Apr 11 19:32:46 myvolumio volumio[823]: info: Loading plugin "upnp"... Apr 11 19:32:46 myvolumio volumio[823]: info: [1775925166799] Starting Upmpd Daemon Apr 11 19:32:46 myvolumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 11 19:32:46 myvolumio volumio[823]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 19:32:46 myvolumio volumio[823]: Error: listen EADDRINUSE: address already in use :::6599 Apr 11 19:32:46 myvolumio volumio[823]: at Server.setupListenHandle [as _listen2] (net.js:1318:16) Apr 11 19:32:46 myvolumio volumio[823]: at listenInCluster (net.js:1366:12) Apr 11 19:32:46 myvolumio volumio[823]: at Server.listen (net.js:1452:7) Apr 11 19:32:46 myvolumio volumio[823]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Apr 11 19:32:46 myvolumio volumio[823]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Apr 11 19:32:46 myvolumio volumio[823]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Apr 11 19:32:46 myvolumio volumio[823]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Apr 11 19:32:46 myvolumio volumio[823]: at processTicksAndRejections (internal/process/task_queues.js:75:11) { Apr 11 19:32:46 myvolumio volumio[823]: code: 'EADDRINUSE', Apr 11 19:32:46 myvolumio volumio[823]: errno: -98, Apr 11 19:32:46 myvolumio volumio[823]: syscall: 'listen', Apr 11 19:32:46 myvolumio volumio[823]: address: '::', Apr 11 19:32:46 myvolumio volumio[823]: port: 6599 Apr 11 19:32:46 myvolumio volumio[823]: } Apr 11 19:32:46 myvolumio volumio[823]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 19:32:47 myvolumio sudo[1834]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-04-11 19:31 Apr 11 19:32:47 myvolumio sudo[1834]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="464fc672d77d3df6ee72b331d36cdf1fa936e1ec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 10:59:40 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="37c6ab864cb114e1344d540995c69f86"