Apr 11 20:27:04 volumio-4 volumio[1222]: info: Bluetoothremote--- Checking for trusted devices to reconnect... Apr 11 20:27:04 volumio-4 volumio[1222]: info: Bluetoothremote--- Device list cleared and placeholder written. Apr 11 20:27:04 volumio-4 bluetoothd[758]: Adv Monitor app :1.20 disconnected from D-Bus Apr 11 20:27:05 volumio-4 volumio[1222]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 11 20:27:05 volumio-4 volumio[1222]: info: Bluetoothremote--- Device found: Press scan to detect BT device - xx Apr 11 20:27:05 volumio-4 bluetoothd[758]: Adv Monitor app :1.21 disconnected from D-Bus Apr 11 20:27:07 volumio-4 kernel: vc4-drm gpu: [drm] *ERROR* flip_done timed out Apr 11 20:27:07 volumio-4 kernel: vc4-drm gpu: [drm] *ERROR* Timed out waiting for commit Apr 11 20:27:09 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 20:27:09 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 20:27:09 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 11 20:27:09 volumio-4 volumio[1222]: error: Plugin system_controller volumio5onboarding failed to complete 'onStart' in a timely fashion Apr 11 20:27:09 volumio-4 volumio[1222]: error: Plugin music_service mpd failed to complete 'onStart' in a timely fashion Apr 11 20:27:09 volumio-4 volumio[1222]: info: ------------------------------------------- Apr 11 20:27:09 volumio-4 volumio[1222]: info: ----- MyVolumio plugins startup ---- Apr 11 20:27:09 volumio-4 volumio[1222]: info: ------------------------------------------- Apr 11 20:27:09 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 11 20:27:17 volumio-4 kernel: vc4-drm gpu: [drm] *ERROR* [CRTC:100:pixelvalve-2] flip_done timed out Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 11 20:27:18 volumio-4 volumio[1222]: info: Adding plugin bluetooth to MyMusic Plugins Apr 11 20:27:18 volumio-4 volumio[1222]: info: Adding plugin multiroom to MyMusic Plugins Apr 11 20:27:18 volumio-4 volumio[1222]: info: Adding plugin metavolumio to MyMusic Plugins Apr 11 20:27:18 volumio-4 volumio[1222]: info: Adding plugin cd_controller to MyMusic Plugins Apr 11 20:27:18 volumio-4 volumio[1222]: info: Adding plugin qobuzconnect to MyMusic Plugins Apr 11 20:27:18 volumio-4 volumio[1222]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 11 20:27:18 volumio-4 volumio[1222]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 11 20:27:18 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 11 20:27:20 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 11 20:27:20 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 11 20:27:20 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 20:27:20 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 20:27:21 volumio-4 volumio[1222]: info: Starting MyVolumio Remote Streaming Endpoints Apr 11 20:27:21 volumio-4 volumio[1222]: info: MyVolumio login type: Token Apr 11 20:27:21 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 11 20:27:21 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 11 20:27:23 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 11 20:27:23 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 11 20:27:23 volumio-4 volumio[1222]: info: Streaming services startup Apr 11 20:27:23 volumio-4 volumio[1222]: info: Starting Streaming Daemon Apr 11 20:27:23 volumio-4 sudo[1773]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 11 20:27:23 volumio-4 sudo[1773]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 20:27:23 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 11 20:27:24 volumio-4 volumio[1222]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 11 20:27:25 volumio-4 volumio[1222]: info: MyVolumio token set successfully Apr 11 20:27:25 volumio-4 volumio[1222]: info: MYVOLUMIO: Adding device Apr 11 20:27:25 volumio-4 volumio[1222]: info: MYVOLUMIO: Evaluating Server Apr 11 20:27:25 volumio-4 volumio[1222]: info: MyVolumio Plan changed: premium Apr 11 20:27:25 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Apr 11 20:27:26 volumio-4 volumio[1222]: info: Removing browser output: myVolumio user plan is not superstar Apr 11 20:27:26 volumio-4 volumio[1222]: info: Removing audio output: Apr 11 20:27:26 volumio-4 volumio[1222]: info: MYVOLUMIO: Adding device Apr 11 20:27:26 volumio-4 volumio[1222]: info: MYVOLUMIO: Evaluating Server Apr 11 20:27:26 volumio-4 volumio[1222]: info: Remote config written successfully Apr 11 20:27:26 volumio-4 volumio[1222]: info: Starting Tunnel 1 Apr 11 20:27:26 volumio-4 volumio[1222]: info: Starting Tunnel Connection Checker Apr 11 20:27:26 volumio-4 volumio[1222]: info: Completed starting MyVolumio Plugin Apr 11 20:27:26 volumio-4 volumio[1222]: info: Setting Geolocation for MyVolumio to eu6 Apr 11 20:27:26 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 20:27:26 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 20:27:26 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 20:27:26 volumio-4 volumio[1222]: info: MYVolumio Device enabled Apr 11 20:27:26 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Apr 11 20:27:26 volumio-4 volumio[1222]: info: MyVolumio status changed Apr 11 20:27:26 volumio-4 volumio[1222]: info: Streaming services startup Apr 11 20:27:26 volumio-4 volumio[1222]: info: Starting Streaming Daemon Apr 11 20:27:26 volumio-4 sudo[1832]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 11 20:27:26 volumio-4 sudo[1832]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 20:27:26 volumio-4 volumio[1222]: info: Setting Geolocation for MyVolumio to eu4 Apr 11 20:27:26 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 20:27:26 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 20:27:26 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 20:27:26 volumio-4 volumio[1222]: info: Successfully Added MyVolumio device Apr 11 20:27:27 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Apr 11 20:27:27 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Apr 11 20:27:27 volumio-4 kernel: vc4-drm gpu: [drm] *ERROR* flip_done timed out Apr 11 20:27:27 volumio-4 kernel: vc4-drm gpu: [drm] *ERROR* [CRTC:100:pixelvalve-2] commit wait timed out Apr 11 20:27:28 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin bluetooth Apr 11 20:27:28 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin bluetooth Apr 11 20:27:28 volumio-4 volumio[1222]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Apr 11 20:27:28 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Apr 11 20:27:29 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Apr 11 20:27:29 volumio-4 sudo[1837]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Apr 11 20:27:29 volumio-4 sudo[1837]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 20:27:29 volumio-4 sudo[1837]: pam_unix(sudo:session): session closed for user root Apr 11 20:27:29 volumio-4 volumio[1222]: info: MRS: MultiRoom plugin initialized Apr 11 20:27:29 volumio-4 volumio[1222]: info: MRS: STOPPING SNAPCLIENT Apr 11 20:27:29 volumio-4 volumio[1222]: info: MRS: Snap server stop Apr 11 20:27:29 volumio-4 volumio[1222]: info: MRS: STOPPING volumioStreaming Apr 11 20:27:29 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Apr 11 20:27:30 volumio-4 sudo[1858]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Apr 11 20:27:30 volumio-4 sudo[1860]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Apr 11 20:27:30 volumio-4 sudo[1860]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 20:27:30 volumio-4 sudo[1854]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Apr 11 20:27:30 volumio-4 sudo[1854]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 20:27:30 volumio-4 sudo[1860]: pam_unix(sudo:session): session closed for user root Apr 11 20:27:30 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Apr 11 20:27:30 volumio-4 sudo[1856]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Apr 11 20:27:30 volumio-4 sudo[1858]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 20:27:30 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Apr 11 20:27:30 volumio-4 sudo[1856]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 20:27:30 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Apr 11 20:27:30 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Apr 11 20:27:30 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Apr 11 20:27:30 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Apr 11 20:27:30 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Apr 11 20:27:30 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Apr 11 20:27:30 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Apr 11 20:27:30 volumio-4 volumio[1222]: info: Preparing to generate the ALSA configuration file Apr 11 20:27:30 volumio-4 volumio[1222]: info: Updating MyVolumio device info Apr 11 20:27:30 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 20:27:30 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 20:27:30 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 20:27:30 volumio-4 volumio[1222]: info: Updating MyVolumio device info Apr 11 20:27:30 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 20:27:30 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 20:27:30 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 20:27:30 volumio-4 volumio[1222]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Apr 11 20:27:30 volumio-4 volumio[1222]: info: Reading ALSA contributions from plugins. Apr 11 20:27:30 volumio-4 volumio[1222]: info: Successfully Added MyVolumio device Apr 11 20:27:30 volumio-4 volumio[1222]: info: MRS: Removed streaming files Apr 11 20:27:31 volumio-4 volumio[1222]: info: Successfully Updated MyVolumio device Apr 11 20:27:31 volumio-4 volumio[1222]: info: Successfully Updated MyVolumio device Apr 11 20:27:31 volumio-4 volumio[1222]: info: Asound.conf file written Apr 11 20:27:31 volumio-4 sudo[1874]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Apr 11 20:27:31 volumio-4 sudo[1874]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 20:27:31 volumio-4 sudo[1874]: pam_unix(sudo:session): session closed for user root Apr 11 20:27:31 volumio-4 volumio[1222]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Apr 11 20:27:31 volumio-4 volumio[1222]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Apr 11 20:27:31 volumio-4 volumio[1222]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Apr 11 20:27:31 volumio-4 volumio[1222]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:3 use case configuration -2 Apr 11 20:27:31 volumio-4 volumio[1222]: info: Output device has changed, restarting MPD Apr 11 20:27:31 volumio-4 volumio[1222]: info: Output device has changed, restarting Shairport Sync Apr 11 20:27:31 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 20:27:31 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 20:27:31 volumio-4 sudo[1880]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 11 20:27:31 volumio-4 sudo[1880]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 20:27:31 volumio-4 sudo[1882]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 11 20:27:31 volumio-4 sudo[1882]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 20:27:31 volumio-4 volumio[1222]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 11 20:27:31 volumio-4 volumio[1222]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 11 20:27:31 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 20:27:31 volumio-4 sudo[1880]: pam_unix(sudo:session): session closed for user root Apr 11 20:27:31 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Apr 11 20:27:31 volumio-4 volumio[1222]: ------------------------------------ BT MESSAGE: [FUNC] onStart Apr 11 20:27:31 volumio-4 volumio[1222]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Apr 11 20:27:31 volumio-4 volumio[1222]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Apr 11 20:27:31 volumio-4 volumio[1222]: ------------------------------------ BT MESSAGE: [metaCache] Created directory: /tmp/bluetooth-cache/ Apr 11 20:27:31 volumio-4 volumio[1222]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Apr 11 20:27:31 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Apr 11 20:27:31 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Apr 11 20:27:31 volumio-4 volumio[1222]: info: MRS: Pushing multiroomSync output for this device Apr 11 20:27:31 volumio-4 volumio[1222]: info: MRS: Pushing multiroomSync output Apr 11 20:27:31 volumio-4 volumio[1222]: info: Adding audio output: Apr 11 20:27:31 volumio-4 volumio[1222]: info: Adding audio output: Apr 11 20:27:32 volumio-4 bluetoothd[758]: Path / reserved for Adv Monitor app :1.23 Apr 11 20:27:32 volumio-4 volumio[1222]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 11 20:27:32 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 20:27:32 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Apr 11 20:27:32 volumio-4 volumio[1222]: info: Adding METAVOLUMIO REST API Endpoints Apr 11 20:27:32 volumio-4 volumio[1222]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Apr 11 20:27:32 volumio-4 volumio[1222]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Apr 11 20:27:32 volumio-4 volumio[1222]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Apr 11 20:27:32 volumio-4 volumio[1222]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Apr 11 20:27:32 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Apr 11 20:27:32 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Apr 11 20:27:32 volumio-4 volumio[1222]: info: Preparing CD Folders Apr 11 20:27:32 volumio-4 bluetoothd[758]: Adv Monitor app :1.23 disconnected from D-Bus Apr 11 20:27:32 volumio-4 volumio[1222]: info: Adding CD REST API Endpoints Apr 11 20:27:32 volumio-4 volumio[1222]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Apr 11 20:27:32 volumio-4 volumio[1222]: info: Starting UDEV Watcher for CD Apr 11 20:27:32 volumio-4 volumio[1222]: info: Detecting CD presence with UDEV Apr 11 20:27:32 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Apr 11 20:27:37 volumio-4 volumio[1222]: warn: [cd-plugin] cdspeedctl: device or media not ready Apr 11 20:27:37 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Apr 11 20:27:37 volumio-4 volumio[1222]: info: Adding inputs REST Endpoints Apr 11 20:27:37 volumio-4 volumio[1222]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Apr 11 20:27:37 volumio-4 volumio[1222]: info: Scanning Audio Inputs Apr 11 20:27:37 volumio-4 volumio[1222]: info: Checking against Known Cards name Apr 11 20:27:37 volumio-4 volumio[1222]: info: Adding Server instance for streaming Apr 11 20:27:37 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Apr 11 20:27:37 volumio-4 volumio[1222]: error: Hi Res Audio Failed Login: Missing Login Data Apr 11 20:27:37 volumio-4 volumio[1222]: info: Adding HIGHRESAUDIO REST API Endpoints Apr 11 20:27:37 volumio-4 volumio[1222]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Apr 11 20:27:37 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Apr 11 20:27:37 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Apr 11 20:27:37 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Apr 11 20:27:37 volumio-4 volumio[1222]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Apr 11 20:27:37 volumio-4 volumio[1222]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Apr 11 20:27:37 volumio-4 sudo[1917]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 11 20:27:37 volumio-4 volumio[1222]: info: QobuzConnect: Starting Qobuz Connect socket and service Apr 11 20:27:37 volumio-4 sudo[1917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 20:27:37 volumio-4 sudo[1923]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Apr 11 20:27:37 volumio-4 sudo[1923]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 20:27:37 volumio-4 volumio[1222]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Apr 11 20:27:37 volumio-4 volumio[1222]: info: Adding TIDAL REST API Endpoints Apr 11 20:27:37 volumio-4 volumio[1222]: info: Stopping AccessToken refresher cron for QOBUZ Apr 11 20:27:37 volumio-4 volumio[1222]: info: AccessToken refresher cron started for QOBUZ Apr 11 20:27:37 volumio-4 volumio[1222]: info: Adding QOBUZ REST API Endpoints Apr 11 20:27:37 volumio-4 volumio[1222]: info: MRS: Getting audio outputs on start Apr 11 20:27:37 volumio-4 volumio[1222]: info: MRS: Requesting all other devices output Apr 11 20:27:37 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 11 20:27:38 volumio-4 kernel: vc4-drm gpu: [drm] *ERROR* flip_done timed out Apr 11 20:27:38 volumio-4 kernel: vc4-drm gpu: [drm] *ERROR* [CONNECTOR:33:HDMI-A-1] commit wait timed out Apr 11 20:27:38 volumio-4 volumio[1222]: info: MRS: Adding multiroomSync output Apr 11 20:27:38 volumio-4 volumio[1222]: info: Adding audio output: Apr 11 20:27:38 volumio-4 volumio[1222]: info: MRS: Pushing multiroomSync output Apr 11 20:27:38 volumio-4 volumio[1222]: info: MRS: Adding multiroomSync output Apr 11 20:27:38 volumio-4 volumio[1222]: info: Adding audio output: Apr 11 20:27:38 volumio-4 volumio[1222]: info: MRS: Pushing multiroomSync output Apr 11 20:27:38 volumio-4 volumio[1222]: info: MRS: Adding multiroomSync output Apr 11 20:27:38 volumio-4 volumio[1222]: info: Adding audio output: Apr 11 20:27:38 volumio-4 volumio[1222]: info: MRS: Pushing multiroomSync output Apr 11 20:27:38 volumio-4 volumio[1222]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Apr 11 20:27:38 volumio-4 volumio[1222]: info: MPD Permissions set Apr 11 20:27:38 volumio-4 sudo[1927]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Apr 11 20:27:38 volumio-4 sudo[1927]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 20:27:38 volumio-4 sudo[1929]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Apr 11 20:27:38 volumio-4 sudo[1929]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 20:27:38 volumio-4 volumio[1222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 19 Apr 11 20:27:38 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 20:27:38 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 20:27:38 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 20:27:38 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 20:27:38 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 20:27:38 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 20:27:38 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 20:27:38 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 20:27:38 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 20:27:38 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 20:27:39 volumio-4 volumio[1222]: info: MRS: Found cast device: IP1800-5971460ca3e07523aed2735366fc54c9 Apr 11 20:27:39 volumio-4 volumio[1222]: info: Adding audio output: Apr 11 20:27:39 volumio-4 volumio[1222]: info: Starting Shairport Sync Apr 11 20:27:39 volumio-4 volumio[1222]: info: CoreCommandRouter::volumioGetState Apr 11 20:27:39 volumio-4 volumio[1222]: info: CorePlayQueue::getTrack 0 Apr 11 20:27:39 volumio-4 sudo[1940]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 11 20:27:39 volumio-4 sudo[1940]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 20:27:41 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 20:27:41 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 20:27:41 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Apr 11 20:27:41 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Apr 11 20:27:41 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 11 20:27:41 volumio-4 volumio[1222]: info: CoreCommandRouter::volumioGetBrowseSources Apr 11 20:27:41 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 11 20:27:48 volumio-4 kernel: vc4-drm gpu: [drm] *ERROR* flip_done timed out Apr 11 20:27:48 volumio-4 kernel: vc4-drm gpu: [drm] *ERROR* [PLANE:89:plane-3] commit wait timed out Apr 11 20:27:56 volumio-4 volumio[1222]: error: MyVolumio Plugins failed to start in a timely fashion Apr 11 20:27:56 volumio-4 volumio[1222]: error: Plugin audio_interface bluetooth failed to complete 'onStart' in a timely fashion Apr 11 20:27:56 volumio-4 volumio[1222]: error: Plugin music_service tidalconnect failed to complete 'onStart' in a timely fashion Apr 11 20:27:56 volumio-4 volumio[1222]: error: Plugin music_service qobuzconnect failed to complete 'onStart' in a timely fashion Apr 11 20:27:56 volumio-4 volumio[1222]: [Metrics] CommandRouter: 97s 12.82ms Apr 11 20:27:56 volumio-4 volumio[1222]: info: CoreCommandRouter::volumiosetStartupVolume Apr 11 20:27:56 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 11 20:27:56 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 11 20:27:56 volumio-4 volumio[1222]: info: CoreCommandRouter::Close All Modals sent Apr 11 20:27:56 volumio-4 volumio[1222]: info: CoreCommandRouter::Close All Modals sent Apr 11 20:27:57 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Apr 11 20:27:57 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 11 20:27:57 volumio-4 volumio[1222]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Apr 11 20:27:58 volumio-4 kernel: vc4-drm gpu: [drm] *ERROR* flip_done timed out Apr 11 20:27:58 volumio-4 kernel: vc4-drm gpu: [drm] *ERROR* Timed out waiting for commit Apr 11 20:28:03 volumio-4 volumio[1222]: info: BOOT COMPLETED Apr 11 20:28:06 volumio-4 sudo[1578]: pam_unix(sudo:session): session closed for user root Apr 11 20:28:06 volumio-4 volumio[1222]: error: Cannot start Upmpdcli: Error: Command failed: /usr/bin/sudo /bin/systemctl start upmpdcli.service Apr 11 20:28:06 volumio-4 volumio[1222]: Failed to start upmpdcli.service: Transport endpoint is not connected Apr 11 20:28:06 volumio-4 volumio[1222]: See system logs and 'systemctl status upmpdcli.service' for details. Apr 11 20:28:08 volumio-4 sudo[1610]: pam_unix(sudo:session): session closed for user root Apr 11 20:28:08 volumio-4 volumio[1222]: info: Cannot restart MPD: Error: Command failed: /usr/bin/sudo /bin/systemctl restart mpd.service Apr 11 20:28:08 volumio-4 volumio[1222]: Failed to restart mpd.service: Transport endpoint is not connected Apr 11 20:28:08 volumio-4 volumio[1222]: See system logs and 'systemctl status mpd.service' for details. Apr 11 20:28:08 volumio-4 volumio[1222]: error: MPD error: Error: connect ENOENT /run/mpd/socket Apr 11 20:28:08 volumio-4 volumio[1222]: error: connect ENOENT /run/mpd/socket {"address":"/run/mpd/socket","code":"ENOENT","errno":-2,"syscall":"connect"} Apr 11 20:28:08 volumio-4 sudo[1617]: pam_unix(sudo:session): session closed for user root Apr 11 20:28:08 volumio-4 volumio[1222]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 20:28:08 volumio-4 volumio[1222]: Error: Command failed: /usr/bin/sudo /bin/systemctl start volumio5-onboarding.service Apr 11 20:28:08 volumio-4 volumio[1222]: Failed to start volumio5-onboarding.service: Transport endpoint is not connected Apr 11 20:28:08 volumio-4 volumio[1222]: See system logs and 'systemctl status volumio5-onboarding.service' for details. Apr 11 20:28:08 volumio-4 volumio[1222]: at ChildProcess.exithandler (node:child_process:421:12) Apr 11 20:28:08 volumio-4 volumio[1222]: at ChildProcess.emit (node:events:514:28) Apr 11 20:28:08 volumio-4 volumio[1222]: at maybeClose (node:internal/child_process:1105:16) Apr 11 20:28:08 volumio-4 volumio[1222]: at Socket. (node:internal/child_process:457:11) Apr 11 20:28:08 volumio-4 volumio[1222]: at Socket.emit (node:events:514:28) Apr 11 20:28:08 volumio-4 volumio[1222]: at Pipe. (node:net:337:12) { Apr 11 20:28:08 volumio-4 volumio[1222]: code: 1, Apr 11 20:28:08 volumio-4 volumio[1222]: killed: false, Apr 11 20:28:08 volumio-4 volumio[1222]: signal: null, Apr 11 20:28:08 volumio-4 volumio[1222]: cmd: '/usr/bin/sudo /bin/systemctl start volumio5-onboarding.service', Apr 11 20:28:08 volumio-4 volumio[1222]: stdout: '', Apr 11 20:28:08 volumio-4 volumio[1222]: stderr: 'Failed to start volumio5-onboarding.service: Transport endpoint is not connected\n' + Apr 11 20:28:08 volumio-4 volumio[1222]: "See system logs and 'systemctl status volumio5-onboarding.service' for details.\n" Apr 11 20:28:08 volumio-4 volumio[1222]: } Apr 11 20:28:08 volumio-4 volumio[1222]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 20:28:08 volumio-4 sudo[1622]: pam_unix(sudo:session): session closed for user root Apr 11 20:28:08 volumio-4 kernel: vc4-drm gpu: [drm] *ERROR* [CRTC:100:pixelvalve-2] flip_done timed out Apr 11 20:28:08 volumio-4 systemd[1]: Received SIGRTMIN+21 from PID 331 (plymouthd). Apr 11 20:28:08 volumio-4 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Apr 11 20:28:08 volumio-4 systemd[1]: Finished plymouth-quit-wait.service - Hold until boot process finishes up. Apr 11 20:28:08 volumio-4 systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 20:28:08 volumio-4 systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 20:28:09 volumio-4 sudo[1773]: pam_unix(sudo:session): session closed for user root Apr 11 20:28:09 volumio-4 sudo[1832]: pam_unix(sudo:session): session closed for user root Apr 11 20:28:09 volumio-4 sudo[1923]: pam_unix(sudo:session): session closed for user root Apr 11 20:28:09 volumio-4 systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 20:28:09 volumio-4 systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 11 20:28:09 volumio-4 sudo[2001]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Apr 11 20:28:09 volumio-4 sudo[2001]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 20:28:09 volumio-4 systemd[1]: Started getty@tty1.service - Getty on tty1. Apr 11 20:28:09 volumio-4 systemd[1]: Reached target getty.target - Login Prompts. Apr 11 20:28:09 volumio-4 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 11 20:28:09 volumio-4 go-librespot[2004]: go-librespot daemon starting... Apr 11 20:28:09 volumio-4 systemd[1]: Starting lircd-setup.service - lircd(8) initialization helper tool... Apr 11 20:28:09 volumio-4 sudo[1657]: pam_unix(sudo:session): session closed for user root Apr 11 20:28:09 volumio-4 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 11 20:28:09 volumio-4 systemd[1]: Starting mpd.service - Music Player Daemon... Apr 11 20:28:09 volumio-4 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 11 20:28:09 volumio-4 systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Apr 11 20:28:09 volumio-4 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Apr 11 20:28:09 volumio-4 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Apr 11 20:28:09 volumio-4 autossh[2010]: port set to 0, monitoring disabled Apr 11 20:28:09 volumio-4 autossh[2010]: starting ssh (count 1) Apr 11 20:28:09 volumio-4 autossh[2010]: ssh child pid is 2014 Apr 11 20:28:09 volumio-4 sudo[2008]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 11 20:28:09 volumio-4 sudo[2008]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 11 20:28:09 volumio-4 lircd-setup[2005]: /usr/sbin/lircd-setup:37: DeprecationWarning: The SafeConfigParser class has been renamed to ConfigParser in Python 3.2. This alias will be removed in Python 3.12. Use ConfigParser directly instead. Apr 11 20:28:09 volumio-4 lircd-setup[2005]: parser = configparser.SafeConfigParser() Apr 11 20:28:09 volumio-4 sudo[2025]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Apr 11 20:28:09 volumio-4 sudo[2008]: pam_unix(sudo:session): session closed for user root Apr 11 20:28:09 volumio-4 systemd[1]: shairport-sync.service: Deactivated successfully. Apr 11 20:28:09 volumio-4 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 11 20:28:09 volumio-4 systemd[1]: shairport-sync.service: Consumed 1.161s CPU time. Apr 11 20:28:09 volumio-4 systemd[1]: lircd-setup.service: Deactivated successfully. Apr 11 20:28:09 volumio-4 systemd[1]: Finished lircd-setup.service - lircd(8) initialization helper tool. Apr 11 20:28:09 volumio-4 volumiossh-tunnel[2014]: Warning: Permanently added '[eu4.myvolumio.org]:2222' (RSA) to the list of known hosts. Apr 11 20:28:09 volumio-4 go-librespot[2006]: time="2026-04-11T20:28:09+02:00" level=info msg="running go-librespot 0.7.1" Apr 11 20:28:09 volumio-4 go-librespot[2006]: time="2026-04-11T20:28:09+02:00" level=debug msg="app state loaded" Apr 11 20:28:10 volumio-4 go-librespot[2006]: time="2026-04-11T20:28:10+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 11 20:28:10 volumio-4 sudo[1858]: pam_unix(sudo:session): session closed for user root Apr 11 20:28:10 volumio-4 sudo[1854]: pam_unix(sudo:session): session closed for user root Apr 11 20:28:10 volumio-4 sudo[1917]: pam_unix(sudo:session): session closed for user root Apr 11 20:28:10 volumio-4 sudo[1856]: pam_unix(sudo:session): session closed for user root Apr 11 20:28:10 volumio-4 sudo[1929]: pam_unix(sudo:session): session closed for user root Apr 11 20:28:10 volumio-4 systemd[1]: Starting lircd.service - Flexible IR remote input/output application support... Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Info: lircd: Opening log, level: Info Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Notice: Version: lircd 0.10.1 Apr 11 20:28:10 volumio-4 systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Notice: System info: Linux volumio-4 6.12.74-v7l+ #1948 SMP Mon Mar 2 11:27:49 GMT 2026 armv7l GNU/Linux Apr 11 20:28:10 volumio-4 sudo[2001]: pam_unix(sudo:session): session closed for user root Apr 11 20:28:10 volumio-4 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 11 20:28:10 volumio-4 sudo[1673]: pam_unix(sudo:session): session closed for user root Apr 11 20:28:10 volumio-4 systemd[1]: Reached target multi-user.target - Multi-User System. Apr 11 20:28:10 volumio-4 systemd[1]: Reached target graphical.target - Graphical Interface. Apr 11 20:28:10 volumio-4 sudo[1675]: pam_unix(sudo:session): session closed for user root Apr 11 20:28:10 volumio-4 sudo[1671]: pam_unix(sudo:session): session closed for user root Apr 11 20:28:10 volumio-4 systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... Apr 11 20:28:10 volumio-4 systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Info: Initial device: /dev/lirc0 Apr 11 20:28:10 volumio-4 lircd[2035]: lircd-0.10.1[2035]: Info: lircd: Opening log, level: Info Apr 11 20:28:10 volumio-4 lircd[2035]: lircd-0.10.1[2035]: Notice: Using systemd fd Apr 11 20:28:10 volumio-4 lircd[2035]: lircd-0.10.1[2035]: Warning: Running as root Apr 11 20:28:10 volumio-4 lircd[2035]: lircd-0.10.1[2035]: Info: Using remote: lircd.conf. Apr 11 20:28:10 volumio-4 lircd[2035]: lircd-0.10.1[2035]: Notice: lircd(default) ready, using /var/run/lirc/lircd Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Notice: 'lirc' written to protocols file /sys/class/rc/rc2/protocols Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Info: Initial device: /dev/lirc0 Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Info: [lirc] protocol is enabled Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Notice: Options: driver: default Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Notice: Options: output: /var/run/lirc/lircd Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Notice: Options: nodaemon: 1 Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Notice: Options: plugindir: /usr/lib/arm-linux-gnueabihf/lirc/plugins Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Notice: Options: logfile: syslog Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Notice: Options: immediate-init: 0 Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Notice: Options: permission: 666 Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Notice: Options: driver-options: Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Notice: Options: pidfile: /var/run/lirc/lircd.pid Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Notice: Options: listen: 0 Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Notice: Options: connect: (null) Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Notice: Options: userelease: 0 Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Notice: Options: effective_user: (null) Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Notice: Options: release_suffix: _EVUP Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Notice: Options: allow_simulate: 0 Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Notice: Options: repeat_max: 600 Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Notice: Options: configfile: /etc/lirc/lircd.conf Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Notice: Options: dynamic_codes: (null) Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Notice: Current driver: default Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Notice: Driver API version: 3 Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Notice: Driver version: 0.10.0 Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Notice: Driver info: See file:///usr/share/doc/lirc/plugindocs/default.html Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Info: lircd: Opening log, level: Info Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Notice: Using systemd fd Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Warning: Running as root Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Info: Using remote: lircd.conf. Apr 11 20:28:10 volumio-4 lircd-0.10.1[2035]: Notice: lircd(default) ready, using /var/run/lirc/lircd Apr 11 20:28:10 volumio-4 volumiobt[2055]: INFO [BTSTART] Ensuring Bluetooth directory exists... Apr 11 20:28:10 volumio-4 sudo[1927]: pam_unix(sudo:session): session closed for user root Apr 11 20:28:10 volumio-4 sudo[2056]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Apr 11 20:28:10 volumio-4 systemd[1]: Started lircd.service - Flexible IR remote input/output application support. Apr 11 20:28:10 volumio-4 sudo[2056]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 20:28:10 volumio-4 sudo[2056]: pam_unix(sudo:session): session closed for user root Apr 11 20:28:10 volumio-4 sudo[2058]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Apr 11 20:28:10 volumio-4 sudo[2058]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 11 20:28:10 volumio-4 sudo[2058]: pam_unix(sudo:session): session closed for user root Apr 11 20:28:10 volumio-4 volumiobt[2060]: INFO [BTSTART] Powering on Bluetooth if needed... Apr 11 20:28:10 volumio-4 sudo[1715]: pam_unix(sudo:session): session closed for user root Apr 11 20:28:10 volumio-4 systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. Apr 11 20:28:10 volumio-4 systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. Apr 11 20:28:11 volumio-4 sudo[1720]: pam_unix(sudo:session): session closed for user root Apr 11 20:28:11 volumio-4 sudo[1940]: pam_unix(sudo:session): session closed for user root Apr 11 20:28:11 volumio-4 bluetoothd[758]: Path / reserved for Adv Monitor app :1.28 Apr 11 20:28:11 volumio-4 bluetoothd[758]: Adv Monitor app :1.28 disconnected from D-Bus Apr 11 20:28:11 volumio-4 volumiobt[2066]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Apr 11 20:28:11 volumio-4 volumiobt[2067]: [176B blob data] Apr 11 20:28:11 volumio-4 volumiobt[2067]: [157B blob data] Apr 11 20:28:11 volumio-4 volumiobt[2067]: [157B blob data] Apr 11 20:28:11 volumio-4 volumiobt[2067]: [157B blob data] Apr 11 20:28:11 volumio-4 volumiobt[2067]: [113B blob data] Apr 11 20:28:11 volumio-4 volumiobt[2067]: [bluetoothctl]> discoverable on Apr 11 20:28:11 volumio-4 volumiobt[2067]: Warning: setting discoverable while discoverable-timeout not set(0) is not recommended Apr 11 20:28:11 volumio-4 volumiobt[2067]: [bluetoothctl]> pairable on Apr 11 20:28:11 volumio-4 bluetoothd[758]: Path / reserved for Adv Monitor app :1.29 Apr 11 20:28:11 volumio-4 kernel: hwmon hwmon1: Undervoltage detected! Apr 11 20:28:11 volumio-4 bluetoothd[758]: Adv Monitor app :1.29 disconnected from D-Bus Apr 11 20:28:11 volumio-4 volumiobt[2067]: [bluetoothctl]> Apr 11 20:28:11 volumio-4 volumiobt[2069]: INFO [BTSTART] Registering Bluetooth agent... Apr 11 20:28:11 volumio-4 volumiobt[2070]: [NEW] Media /org/bluez/hci0 Apr 11 20:28:11 volumio-4 volumiobt[2070]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Apr 11 20:28:11 volumio-4 volumiobt[2070]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Apr 11 20:28:11 volumio-4 volumiobt[2070]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb Apr 11 20:28:11 volumio-4 go-librespot[2006]: time="2026-04-11T20:28:11+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 11 20:28:11 volumio-4 go-librespot[2006]: time="2026-04-11T20:28:11+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 11 20:28:11 volumio-4 go-librespot[2006]: time="2026-04-11T20:28:11+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 11 20:28:11 volumio-4 bluetoothd[758]: Adv Monitor app :1.30 disconnected from D-Bus Apr 11 20:28:11 volumio-4 go-librespot[2006]: time="2026-04-11T20:28:11+02:00" level=info msg="zeroconf server listening on port 36427" Apr 11 20:28:11 volumio-4 go-librespot[2006]: time="2026-04-11T20:28:11+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Apr 11 20:28:11 volumio-4 volumiobt[2071]: No agent is registered Apr 11 20:28:11 volumio-4 volumiobt[2071]: [NEW] Media /org/bluez/hci0 Apr 11 20:28:11 volumio-4 volumiobt[2071]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Apr 11 20:28:11 volumio-4 volumiobt[2071]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Apr 11 20:28:11 volumio-4 volumiobt[2071]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb Apr 11 20:28:11 volumio-4 bluetoothd[758]: Adv Monitor app :1.31 disconnected from D-Bus Apr 11 20:28:11 volumio-4 volumiobt[2072]: INFO [BTSTART] Agent registered successfully. Apr 11 20:28:11 volumio-4 volumiobt[2073]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Apr 11 20:28:11 volumio-4 go-librespot[2006]: time="2026-04-11T20:28:11+02:00" level=debug msg="obtained new client token: AACI0RlLh7mpk3hSQPfIdaxQVkyt50ztk8gxWwDapV1dlO+G2ZixcHmN/6pU/izFINEtT1rdtBKU7FAHWYzxAzFup+mnRauGfH597Ml7v+DKfoKhwHfyK0+32dOnQfqRZ/sNEi7WM3gRm9PJ9Gd+sOPTVkZmQXs6ksSRnY+yKaXlxIpkI9HZIps7YwjGiJDMZ4xtJd4PMk3QfbXjdmesWPOSJ6B4WS+1qOQUZCbdmH5pu8/DqHl3pgmcy2Q=" Apr 11 20:28:11 volumio-4 go-librespot[2006]: time="2026-04-11T20:28:11+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Apr 11 20:28:12 volumio-4 go-librespot[2006]: time="2026-04-11T20:28:12+02:00" level=debug msg="completed keyexchange" Apr 11 20:28:12 volumio-4 go-librespot[2006]: time="2026-04-11T20:28:12+02:00" level=debug msg="completed challenge" Apr 11 20:28:12 volumio-4 go-librespot[2006]: time="2026-04-11T20:28:12+02:00" level=info msg="authenticated AP" username="ra*****es" Apr 11 20:28:12 volumio-4 go-librespot[2006]: time="2026-04-11T20:28:12+02:00" level=info msg="authenticated Login5" username="ra*****es" Apr 11 20:28:12 volumio-4 go-librespot[2006]: time="2026-04-11T20:28:12+02:00" level=debug msg="initializing zeroconf session" username="ra*****es" Apr 11 20:28:12 volumio-4 go-librespot[2006]: time="2026-04-11T20:28:12+02:00" level=debug msg="dealer connection opened" Apr 11 20:28:12 volumio-4 go-librespot[2006]: time="2026-04-11T20:28:12+02:00" level=trace msg="starting accesspoint recv loop" Apr 11 20:28:12 volumio-4 go-librespot[2006]: time="2026-04-11T20:28:12+02:00" level=trace msg="starting dealer recv loop" Apr 11 20:28:12 volumio-4 go-librespot[2006]: time="2026-04-11T20:28:12+02:00" level=trace msg="received accesspoint ping" Apr 11 20:28:12 volumio-4 go-librespot[2006]: time="2026-04-11T20:28:12+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 11 20:28:12 volumio-4 go-librespot[2006]: time="2026-04-11T20:28:12+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 11 20:28:12 volumio-4 go-librespot[2006]: time="2026-04-11T20:28:12+02:00" level=debug msg="received connection id: OWVmMzIyYzgtODAz...NThBMkFDNUE1MQ==" Apr 11 20:28:12 volumio-4 go-librespot[2006]: time="2026-04-11T20:28:12+02:00" level=debug msg="put connect state because NEW_DEVICE" Apr 11 20:28:12 volumio-4 go-librespot[2006]: time="2026-04-11T20:28:12+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 11 20:28:12 volumio-4 go-librespot[2006]: time="2026-04-11T20:28:12+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 11 20:28:12 volumio-4 go-librespot[2006]: time="2026-04-11T20:28:12+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Apr 11 20:28:12 volumio-4 go-librespot[2006]: time="2026-04-11T20:28:12+02:00" level=trace msg="received accesspoint pong ack" Apr 11 20:28:13 volumio-4 volumiobt[2074]: 2026-04-11 20:28:13 a2dp-agent [INFO] Connecting to system D-Bus Apr 11 20:28:13 volumio-4 volumiobt[2074]: 2026-04-11 20:28:13 a2dp-agent [INFO] Connected to system D-Bus Apr 11 20:28:13 volumio-4 volumiobt[2074]: 2026-04-11 20:28:13 bluezutils [INFO] Found adapter at: /org/bluez/hci0 Apr 11 20:28:13 volumio-4 volumiobt[2074]: 2026-04-11 20:28:13 a2dp-agent [INFO] Found Bluetooth adapter: /org/bluez/hci0 Apr 11 20:28:13 volumio-4 volumiobt[2074]: 2026-04-11 20:28:13 a2dp-agent [INFO] Set DiscoverableTimeout to infinite Apr 11 20:28:13 volumio-4 volumiobt[2074]: 2026-04-11 20:28:13 a2dp-agent [INFO] Enabled Discoverable mode Apr 11 20:28:13 volumio-4 volumiobt[2074]: 2026-04-11 20:28:13 a2dp-agent [INFO] Agent registered at /local/a2dpagent Apr 11 20:28:13 volumio-4 volumiobt[2074]: 2026-04-11 20:28:13 a2dp-agent [INFO] Agent set as default Apr 11 20:28:13 volumio-4 volumiobt[2074]: 2026-04-11 20:28:13 a2dp-agent [INFO] A2DP agent running, waiting for connections... Apr 11 20:28:15 volumio-4 kernel: hwmon hwmon1: Voltage normalised Apr 11 20:28:15 volumio-4 sudo[2081]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-11 20:27' Apr 11 20:28:15 volumio-4 sudo[2081]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"