Apr 12 21:04:17 volumio ntpd[920]: CLOCK: time stepped by 31.357862 Apr 12 21:04:17 volumio ntpd[920]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Apr 12 21:04:25 volumio volumio[1151]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 12 21:04:25 volumio volumio[1151]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 12 21:04:25 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 21:04:25 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 21:04:25 volumio volumio[1151]: info: Starting MyVolumio Remote Streaming Endpoints Apr 12 21:04:25 volumio volumio[1151]: info: MyVolumio login type: Token Apr 12 21:04:26 volumio volumio[1151]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 12 21:04:26 volumio volumio[1151]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 12 21:04:30 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 6. Apr 12 21:04:30 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Apr 12 21:04:30 volumio systemd[1]: upmpdcli.service: Consumed 28.050s CPU time. Apr 12 21:04:30 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Apr 12 21:04:35 volumio volumio[1151]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 12 21:04:35 volumio volumio[1151]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 12 21:04:35 volumio volumio[1151]: info: Streaming services startup Apr 12 21:04:35 volumio volumio[1151]: info: Starting Streaming Daemon Apr 12 21:04:36 volumio sudo[2423]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 12 21:04:36 volumio volumio[1151]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 12 21:04:36 volumio sudo[2423]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:04:36 volumio sudo[2423]: pam_unix(sudo:session): session closed for user root Apr 12 21:04:36 volumio volumio[1151]: info: Discovery: Restarting Advertising Apr 12 21:04:37 volumio sudo[2431]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 12 21:04:37 volumio sudo[2431]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:04:37 volumio volumio[1151]: info: Volumio Network Manager: Network status updated: 2 Apr 12 21:04:37 volumio sudo[2431]: pam_unix(sudo:session): session closed for user root Apr 12 21:04:37 volumio sudo[2433]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 12 21:04:37 volumio sudo[2433]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:04:37 volumio sudo[2433]: pam_unix(sudo:session): session closed for user root Apr 12 21:04:37 volumio volumio[1151]: error: Cannot start Volumio Streaming Daemon Apr 12 21:04:37 volumio volumio[1151]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 12 21:04:37 volumio volumio[1151]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 12 21:04:38 volumio volumio[1151]: verbose: New Socket.io Connection to 192.168.1.147 from 192.168.1.138 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/146.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Apr 12 21:04:38 volumio sudo[2437]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 12 21:04:38 volumio sudo[2437]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:04:38 volumio sudo[2437]: pam_unix(sudo:session): session closed for user root Apr 12 21:04:39 volumio volumio[1151]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 12 21:04:39 volumio volumio[1151]: info: Upmpdcli Daemon Started Apr 12 21:04:40 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 12 21:04:40 volumio volumio[1151]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Apr 12 21:04:41 volumio sudo[2457]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 12 21:04:41 volumio sudo[2457]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:04:41 volumio sudo[2455]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 12 21:04:41 volumio sudo[2455]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:04:41 volumio sudo[2457]: pam_unix(sudo:session): session closed for user root Apr 12 21:04:41 volumio volumio[1151]: info: Discovery: Started advertising with name: Volumio Apr 12 21:04:42 volumio sudo[2455]: pam_unix(sudo:session): session closed for user root Apr 12 21:04:42 volumio upmpdcli[2463]: writing RSA key Apr 12 21:04:42 volumio volumio[1151]: info: CoreCommandRouter::volumioGetState Apr 12 21:04:42 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:04:42 volumio volumio[1151]: verbose: New Socket.io Connection to 192.168.1.147 from 192.168.1.138 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/146.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Apr 12 21:04:43 volumio volumio[1151]: info: MyVolumio token set successfully Apr 12 21:04:43 volumio volumio[1151]: info: MYVOLUMIO: Adding device Apr 12 21:04:43 volumio volumio[1151]: info: MYVOLUMIO: Evaluating Server Apr 12 21:04:44 volumio volumio[1151]: info: MyVolumio Plan changed: premium Apr 12 21:04:44 volumio volumio[1151]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Apr 12 21:04:44 volumio volumio[1151]: info: Removing browser output: myVolumio user plan is not superstar Apr 12 21:04:44 volumio volumio[1151]: info: Removing audio output: Apr 12 21:04:44 volumio volumio[1151]: info: MYVOLUMIO: Adding device Apr 12 21:04:44 volumio volumio[1151]: info: MYVOLUMIO: Evaluating Server Apr 12 21:04:46 volumio volumio[1151]: info: Discovery: this is already registered, e978c57f-7425-451b-8355-62f5458576f4 Apr 12 21:04:46 volumio volumio[1151]: info: Discovery: Found device Volumio Apr 12 21:04:46 volumio volumio[1151]: info: CoreCommandRouter::volumioGetState Apr 12 21:04:46 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:04:46 volumio volumio[1151]: info: Setting Geolocation for MyVolumio to eu7 Apr 12 21:04:46 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 21:04:46 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 21:04:46 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 21:04:46 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 21:04:46 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 21:04:46 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Apr 12 21:04:46 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Apr 12 21:04:46 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 12 21:04:46 volumio volumio[1151]: info: CoreCommandRouter::volumioGetBrowseSources Apr 12 21:04:46 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 12 21:04:47 volumio volumio[1151]: info: Setting Geolocation for MyVolumio to eu11 Apr 12 21:04:47 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 21:04:47 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 21:04:47 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 21:04:47 volumio volumio[1151]: info: Remote config written successfully Apr 12 21:04:47 volumio volumio[1151]: info: Starting Tunnel 1 Apr 12 21:04:47 volumio volumio[1151]: info: Starting Tunnel Connection Checker Apr 12 21:04:47 volumio volumio[1151]: info: Discovery: this is already registered, e978c57f-7425-451b-8355-62f5458576f4 Apr 12 21:04:47 volumio volumio[1151]: info: Discovery: Found device Volumio Apr 12 21:04:47 volumio volumio[1151]: info: CoreCommandRouter::volumioGetState Apr 12 21:04:47 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:04:47 volumio volumio[1151]: info: MYVolumio Device enabled Apr 12 21:04:47 volumio volumio[1151]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Apr 12 21:04:47 volumio volumio[1151]: info: MyVolumio status changed Apr 12 21:04:47 volumio volumio[1151]: info: Streaming services startup Apr 12 21:04:47 volumio volumio[1151]: info: Starting Streaming Daemon Apr 12 21:04:48 volumio volumio[1151]: info: Updating MyVolumio device info Apr 12 21:04:48 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 21:04:48 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 21:04:48 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 21:04:48 volumio sudo[2513]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 12 21:04:48 volumio sudo[2513]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:04:48 volumio sudo[2513]: pam_unix(sudo:session): session closed for user root Apr 12 21:04:48 volumio volumio[1151]: info: Successfully Added MyVolumio device Apr 12 21:04:48 volumio volumio[1151]: info: Successfully Added MyVolumio device Apr 12 21:04:48 volumio volumio[1151]: info: Updating MyVolumio device info Apr 12 21:04:48 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 21:04:48 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 21:04:48 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 21:04:49 volumio volumio[1151]: error: Cannot start Volumio Streaming Daemon Apr 12 21:04:49 volumio volumio[1151]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 12 21:04:49 volumio volumio[1151]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 12 21:04:49 volumio volumio[1151]: info: Successfully Updated MyVolumio device Apr 12 21:04:49 volumio sudo[2527]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 12 21:04:49 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Apr 12 21:04:49 volumio sudo[2527]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:04:49 volumio sudo[2528]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 12 21:04:49 volumio sudo[2527]: pam_unix(sudo:session): session closed for user root Apr 12 21:04:49 volumio sudo[2528]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:04:49 volumio volumio[1151]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Apr 12 21:04:49 volumio sudo[2528]: pam_unix(sudo:session): session closed for user root Apr 12 21:04:50 volumio volumio[1151]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin bluetooth Apr 12 21:04:50 volumio volumio[1151]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin bluetooth Apr 12 21:04:50 volumio volumio[1151]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Apr 12 21:04:50 volumio volumio[1151]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Apr 12 21:04:53 volumio volumio[1151]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Apr 12 21:04:53 volumio sudo[2540]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Apr 12 21:04:53 volumio sudo[2540]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:04:53 volumio sudo[2540]: pam_unix(sudo:session): session closed for user root Apr 12 21:04:53 volumio volumio[1151]: info: MRS: MultiRoom plugin initialized Apr 12 21:04:53 volumio volumio[1151]: info: MRS: STOPPING SNAPCLIENT Apr 12 21:04:53 volumio volumio[1151]: info: MRS: Snap server stop Apr 12 21:04:53 volumio volumio[1151]: info: MRS: STOPPING volumioStreaming Apr 12 21:04:53 volumio sudo[2557]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Apr 12 21:04:53 volumio sudo[2557]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:04:53 volumio volumio[1151]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Apr 12 21:04:53 volumio sudo[2559]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Apr 12 21:04:53 volumio sudo[2559]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:04:53 volumio sudo[2561]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Apr 12 21:04:53 volumio sudo[2561]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:04:53 volumio volumio[1151]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Apr 12 21:04:53 volumio sudo[2564]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Apr 12 21:04:53 volumio sudo[2564]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:04:53 volumio sudo[2564]: pam_unix(sudo:session): session closed for user root Apr 12 21:04:54 volumio volumio[1151]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Apr 12 21:04:54 volumio volumio[1151]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Apr 12 21:04:54 volumio volumio[1151]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Apr 12 21:04:54 volumio sudo[2557]: pam_unix(sudo:session): session closed for user root Apr 12 21:04:54 volumio volumio[1151]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Apr 12 21:04:54 volumio volumio[1151]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Apr 12 21:04:54 volumio sudo[2561]: pam_unix(sudo:session): session closed for user root Apr 12 21:04:54 volumio sudo[2559]: pam_unix(sudo:session): session closed for user root Apr 12 21:04:54 volumio volumio[1151]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Apr 12 21:04:54 volumio volumio[1151]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Apr 12 21:04:54 volumio volumio[1151]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Apr 12 21:04:54 volumio volumio[1151]: info: Preparing to generate the ALSA configuration file Apr 12 21:04:54 volumio volumio[1151]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Apr 12 21:04:54 volumio volumio[1151]: info: Reading ALSA contributions from plugins. Apr 12 21:04:54 volumio volumio[1151]: info: Successfully Updated MyVolumio device Apr 12 21:04:54 volumio volumio[1151]: info: MRS: Removed streaming files Apr 12 21:04:54 volumio volumio[1151]: info: MRS: volumioStreaming STOPPED Apr 12 21:04:54 volumio volumio[1151]: info: MRS: SNAPSERVER STOPPED Apr 12 21:04:54 volumio volumio[1151]: info: MRS: SNAPCLIENT STOPPED Apr 12 21:04:54 volumio volumio[1151]: info: Asound.conf file written Apr 12 21:04:54 volumio sudo[2575]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Apr 12 21:04:54 volumio sudo[2575]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:04:55 volumio sudo[2575]: pam_unix(sudo:session): session closed for user root Apr 12 21:04:55 volumio volumio[1151]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Apr 12 21:04:55 volumio volumio[1151]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Apr 12 21:04:55 volumio volumio[1151]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Apr 12 21:04:55 volumio volumio[1151]: info: Output device has changed, restarting MPD Apr 12 21:04:55 volumio volumio[1151]: info: Output device has changed, restarting Shairport Sync Apr 12 21:04:55 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 21:04:55 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 21:04:55 volumio sudo[2581]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 12 21:04:55 volumio sudo[2581]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:04:55 volumio sudo[2583]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 12 21:04:55 volumio sudo[2583]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:04:55 volumio sudo[2581]: pam_unix(sudo:session): session closed for user root Apr 12 21:04:55 volumio volumio[1151]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 12 21:04:55 volumio volumio[1151]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 12 21:04:55 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 21:04:55 volumio volumio[1151]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Apr 12 21:04:55 volumio volumio[1151]: ------------------------------------ BT MESSAGE: [FUNC] onStart Apr 12 21:04:55 volumio volumio[1151]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Apr 12 21:04:55 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 12 21:04:55 volumio volumio[1151]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Apr 12 21:04:55 volumio volumio[1151]: ------------------------------------ BT MESSAGE: [metaCache] Created directory: /tmp/bluetooth-cache/ Apr 12 21:04:55 volumio volumio[1151]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Apr 12 21:04:55 volumio volumio[1151]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Apr 12 21:04:55 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Apr 12 21:04:55 volumio volumio[1151]: info: MRS: Pushing multiroomSync output for this device Apr 12 21:04:55 volumio volumio[1151]: info: MRS: Pushing multiroomSync output Apr 12 21:04:55 volumio volumio[1151]: info: Adding audio output: Apr 12 21:04:55 volumio volumio[1151]: info: Adding audio output: Apr 12 21:04:55 volumio volumio[1151]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 12 21:04:55 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 21:04:55 volumio volumio[1151]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Apr 12 21:04:55 volumio volumio[1151]: info: Adding METAVOLUMIO REST API Endpoints Apr 12 21:04:55 volumio volumio[1151]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Apr 12 21:04:55 volumio volumio[1151]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Apr 12 21:04:55 volumio volumio[1151]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Apr 12 21:04:55 volumio volumio[1151]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Apr 12 21:04:55 volumio volumio[1151]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Apr 12 21:04:55 volumio volumio[1151]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Apr 12 21:04:55 volumio volumio[1151]: info: Preparing CD Folders Apr 12 21:04:55 volumio volumio[1151]: info: Adding CD REST API Endpoints Apr 12 21:04:55 volumio volumio[1151]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Apr 12 21:04:55 volumio volumio[1151]: info: Starting UDEV Watcher for CD Apr 12 21:04:55 volumio volumio[1151]: info: Detecting CD presence with UDEV Apr 12 21:04:55 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Apr 12 21:04:55 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 12 21:04:55 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 12 21:04:55 volumio systemd[1]: mpd.service: Consumed 9.198s CPU time. Apr 12 21:04:55 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 12 21:04:55 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 12 21:04:55 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 12 21:04:55 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 12 21:04:55 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 12 21:04:56 volumio sudo[2601]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 12 21:04:56 volumio sudo[2601]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 12 21:04:56 volumio sudo[2601]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:00 volumio volumio[1151]: warn: [cd-plugin] cdspeedctl: device or media not ready Apr 12 21:05:00 volumio volumio[1151]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Apr 12 21:05:00 volumio volumio[1151]: info: Adding inputs REST Endpoints Apr 12 21:05:00 volumio volumio[1151]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Apr 12 21:05:00 volumio volumio[1151]: info: Scanning Audio Inputs Apr 12 21:05:00 volumio volumio[1151]: info: Checking against Known Cards name Apr 12 21:05:00 volumio volumio[1151]: info: Adding Server instance for streaming Apr 12 21:05:00 volumio volumio[1151]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Apr 12 21:05:00 volumio volumio[1151]: error: Hi Res Audio Failed Login: Missing Login Data Apr 12 21:05:00 volumio volumio[1151]: info: Adding HIGHRESAUDIO REST API Endpoints Apr 12 21:05:00 volumio volumio[1151]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Apr 12 21:05:00 volumio volumio[1151]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Apr 12 21:05:00 volumio volumio[1151]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Apr 12 21:05:00 volumio volumio[1151]: info: Refreshing QOBUZ token Apr 12 21:05:00 volumio volumio[1151]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Apr 12 21:05:00 volumio volumio[1151]: info: [MyVolumio PluginManager] Plugin tidalconnect disabled by user. Not starting Apr 12 21:05:00 volumio volumio[1151]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Apr 12 21:05:00 volumio volumio[1151]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Apr 12 21:05:00 volumio volumio[1151]: info: QobuzConnect: Starting Qobuz Connect socket and service Apr 12 21:05:00 volumio mpd[2603]: 2026-04-12T21:05:00 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 12 21:05:00 volumio systemd[1]: Started mpd.service - Music Player Daemon. Apr 12 21:05:00 volumio sudo[2583]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:00 volumio sudo[2626]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Apr 12 21:05:00 volumio sudo[2626]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:00 volumio volumio[1151]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Apr 12 21:05:00 volumio volumio[1151]: info: Adding TIDAL REST API Endpoints Apr 12 21:05:00 volumio volumio[1151]: info: MRS: Getting audio outputs on start Apr 12 21:05:00 volumio volumio[1151]: info: MRS: Requesting all other devices output Apr 12 21:05:00 volumio sudo[2626]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:00 volumio sudo[2630]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Apr 12 21:05:00 volumio sudo[2630]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:00 volumio volumio[1151]: ------------------------------------ BT MESSAGE: Failed to power on adapter: Apr 12 21:05:00 volumio volumio[1151]: info: MPD Permissions set Apr 12 21:05:01 volumio sudo[2633]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Apr 12 21:05:01 volumio sudo[2633]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:01 volumio systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Apr 12 21:05:01 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 21:05:01 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 21:05:01 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 21:05:01 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 21:05:01 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 21:05:01 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 21:05:01 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 21:05:01 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 21:05:01 volumio sudo[2630]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:01 volumio sudo[2636]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Apr 12 21:05:01 volumio sudo[2636]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:01 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 21:05:01 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 21:05:01 volumio volumio[1151]: error: updateQueue error: null Apr 12 21:05:01 volumio volumio[1151]: info: Starting Shairport Sync Apr 12 21:05:01 volumio systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:01 volumio 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 12 21:05:01 volumio 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 12 21:05:01 volumio sudo[2633]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:01 volumio volumiobt[2650]: INFO [BTSTART] Ensuring Bluetooth directory exists... Apr 12 21:05:01 volumio systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Apr 12 21:05:01 volumio sudo[2636]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:01 volumio sudo[2652]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Apr 12 21:05:01 volumio sudo[2649]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 12 21:05:01 volumio sudo[2652]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:01 volumio sudo[2649]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:01 volumio sudo[2652]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:01 volumio autossh[2653]: port set to 0, monitoring disabled Apr 12 21:05:01 volumio autossh[2653]: starting ssh (count 1) Apr 12 21:05:01 volumio autossh[2653]: ssh child pid is 2659 Apr 12 21:05:01 volumio sudo[2658]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Apr 12 21:05:01 volumio sudo[2658]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:01 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 12 21:05:01 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 12 21:05:01 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 12 21:05:01 volumio systemd[1]: shairport-sync.service: Consumed 2.054s CPU time. Apr 12 21:05:01 volumio sudo[2658]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:01 volumio volumiobt[2662]: INFO [BTSTART] Powering on Bluetooth if needed... Apr 12 21:05:01 volumio volumio[1151]: info: Executing endpoint qc_getconfig Apr 12 21:05:01 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Apr 12 21:05:01 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 12 21:05:01 volumio sudo[2649]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:01 volumio qobuz-connect[2634]: 20260412 21:05:01.656 [2634.2634] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Apr 12 21:05:01 volumio volumio[1151]: info: MRS: Found cast device: Lenovo-Smart-Clock-28de73f5c8b6eb7fe46f6c00d1f46333 Apr 12 21:05:01 volumio volumio[1151]: info: Adding audio output: Apr 12 21:05:01 volumio volumio[1151]: info: MRS: Found cast device: MIBOX4-09626d1d73a31a4900090b83f6868b3b Apr 12 21:05:01 volumio volumio[1151]: info: Adding audio output: Apr 12 21:05:01 volumio volumiobt[2668]: No default controller available Apr 12 21:05:01 volumio volumio[1151]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Apr 12 21:05:01 volumio volumio[1151]: info: QobuzConnect: QOBUZ Connect daemon connected Apr 12 21:05:01 volumio volumio[1151]: info: Shairport-Sync Started Apr 12 21:05:01 volumio volumio[1151]: info: Remote SSH Started Apr 12 21:05:01 volumio qobuz-connect[2634]: 20260412 21:05:01.912 [2634.2634] INFO VolumeManager: [0x537138]: Setting new playback volume: 75 Apr 12 21:05:01 volumio qobuz-connect[2634]: 20260412 21:05:01.913 [2634.2634] INFO VolumeManager: [0x537138]: Setting new mute state: 0 Apr 12 21:05:01 volumio qobuz-connect[2634]: 20260412 21:05:01.913 [2634.2634] INFO AudioStreamManager: [0x536e90]: Setting new audio download buffer size: 1048576 Apr 12 21:05:01 volumio qobuz-connect[2634]: 20260412 21:05:01.914 [2634.2634] INFO QobuzConnect: [0x537a00]: Client initialized! Apr 12 21:05:01 volumio qobuz-connect[2634]: 20260412 21:05:01.915 [2634.2634] INFO SampleApp: Starting Avahi advertising, name: Volumio, service name: _qobuz-connect._tcp Apr 12 21:05:01 volumio qobuz-connect[2634]: 20260412 21:05:01.988 [2634.2634] INFO LocalConfigManager: [0x536bb8]: Starting Local Configuration server Apr 12 21:05:01 volumio qobuz-connect[2634]: 20260412 21:05:01.988 [2634.2634] INFO SampleApp: Starting Local configuration server Apr 12 21:05:01 volumio volumiossh-tunnel[2659]: Warning: Permanently added '[eu11.myvolumio.org]:2222' (ED25519) to the list of known hosts. Apr 12 21:05:01 volumio qobuz-connect[2634]: 20260412 21:05:01.993 [2634.2634] INFO SampleApp: Connected to UNIX socket client 0x521818 Apr 12 21:05:01 volumio qobuz-connect[2634]: 20260412 21:05:01.994 [2634.2634] INFO SampleApp: Playback volume changed: 75 Apr 12 21:05:02 volumio volumio[1151]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Apr 12 21:05:02 volumio volumio[1151]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Apr 12 21:05:02 volumio volumio[1151]: info: CoreCommandRouter::volumioGetState Apr 12 21:05:02 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:05:02 volumio volumio[1151]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Apr 12 21:05:02 volumio volumio[1151]: info: Access Token successfully retrieved Apr 12 21:05:02 volumio volumio[1151]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 12 21:05:02 volumio volumio[1151]: info: [1776020702530] CoreMusicLibrary::Adding element QOBUZ Apr 12 21:05:02 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 21:05:02 volumio volumio[1151]: Cannot find translation for source Mixcloud Apr 12 21:05:02 volumio volumio[1151]: Cannot find translation for source Podcast Apr 12 21:05:02 volumio volumio[1151]: Cannot find translation for source QOBUZ Apr 12 21:05:02 volumio volumio[1151]: info: Stopping AccessToken refresher cron for QOBUZ Apr 12 21:05:02 volumio volumio[1151]: info: AccessToken refresher cron started for QOBUZ Apr 12 21:05:02 volumio volumio[1151]: info: Adding QOBUZ REST API Endpoints Apr 12 21:05:02 volumio volumio[1151]: info: CoreCommandRouter::volumioGetState Apr 12 21:05:02 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:05:02 volumio volumiobt[2687]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Apr 12 21:05:02 volumio volumiobt[2688]: [83B blob data] Apr 12 21:05:02 volumio volumiobt[2688]: No default controller available Apr 12 21:05:02 volumio volumiobt[2688]: [bluetoothctl]> pairable on Apr 12 21:05:02 volumio volumiobt[2688]: No default controller available Apr 12 21:05:02 volumio volumiobt[2688]: [bluetoothctl]> Apr 12 21:05:02 volumio volumiobt[2689]: INFO [BTSTART] Registering Bluetooth agent... Apr 12 21:05:03 volumio volumiobt[2691]: No agent is registered Apr 12 21:05:03 volumio volumiobt[2692]: INFO [BTSTART] Agent registered successfully. Apr 12 21:05:03 volumio volumiobt[2693]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Apr 12 21:05:04 volumio volumiobt[2694]: 2026-04-12 21:05:04 a2dp-agent [INFO] Connecting to system D-Bus Apr 12 21:05:04 volumio volumiobt[2694]: 2026-04-12 21:05:04 a2dp-agent [INFO] Connected to system D-Bus Apr 12 21:05:04 volumio volumiobt[2694]: 2026-04-12 21:05:04 a2dp-agent [ERROR] No Bluetooth adapter found: Bluetooth adapter not found Apr 12 21:05:04 volumio volumiobt[2694]: 2026-04-12 21:05:04 a2dp-agent [ERROR] Agent crashed: Bluetooth adapter not found Apr 12 21:05:04 volumio volumiobt[2694]: Traceback (most recent call last): Apr 12 21:05:04 volumio volumiobt[2694]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:04 volumio volumiobt[2694]: asyncio.run(_run()) Apr 12 21:05:04 volumio volumiobt[2694]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:04 volumio volumiobt[2694]: return runner.run(main) Apr 12 21:05:04 volumio volumiobt[2694]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:04 volumio volumiobt[2694]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:04 volumio volumiobt[2694]: return self._loop.run_until_complete(task) Apr 12 21:05:04 volumio volumiobt[2694]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:04 volumio volumiobt[2694]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:04 volumio volumiobt[2694]: return future.result() Apr 12 21:05:04 volumio volumiobt[2694]: ^^^^^^^^^^^^^^^ Apr 12 21:05:04 volumio volumiobt[2694]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:04 volumio volumiobt[2694]: adapter_path = await find_adapter(bus) Apr 12 21:05:04 volumio volumiobt[2694]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:04 volumio volumiobt[2694]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:04 volumio volumiobt[2694]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:04 volumio volumiobt[2694]: Exception: Bluetooth adapter not found Apr 12 21:05:04 volumio volumiobt[2694]: Traceback (most recent call last): Apr 12 21:05:04 volumio volumiobt[2694]: File "/bin/bt/a2dp-agent", line 234, in Apr 12 21:05:04 volumio volumiobt[2694]: main() Apr 12 21:05:04 volumio volumiobt[2694]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:04 volumio volumiobt[2694]: asyncio.run(_run()) Apr 12 21:05:04 volumio volumiobt[2694]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:04 volumio volumiobt[2694]: return runner.run(main) Apr 12 21:05:04 volumio volumiobt[2694]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:04 volumio volumiobt[2694]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:04 volumio volumiobt[2694]: return self._loop.run_until_complete(task) Apr 12 21:05:04 volumio volumiobt[2694]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:04 volumio volumiobt[2694]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:04 volumio volumiobt[2694]: return future.result() Apr 12 21:05:04 volumio volumiobt[2694]: ^^^^^^^^^^^^^^^ Apr 12 21:05:04 volumio volumiobt[2694]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:04 volumio volumiobt[2694]: adapter_path = await find_adapter(bus) Apr 12 21:05:04 volumio volumiobt[2694]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:04 volumio volumiobt[2694]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:04 volumio volumiobt[2694]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:04 volumio volumiobt[2694]: Exception: Bluetooth adapter not found Apr 12 21:05:04 volumio systemd[1]: volumiobt.service: Main process exited, code=exited, status=1/FAILURE Apr 12 21:05:04 volumio systemd[1]: volumiobt.service: Failed with result 'exit-code'. Apr 12 21:05:04 volumio systemd[1]: volumiobt.service: Consumed 2.179s CPU time. Apr 12 21:05:05 volumio systemd[1]: volumiobt.service: Scheduled restart job, restart counter is at 1. Apr 12 21:05:05 volumio systemd[1]: Stopped volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:05 volumio systemd[1]: volumiobt.service: Consumed 2.179s CPU time. Apr 12 21:05:05 volumio systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:05 volumio volumiobt[2696]: INFO [BTSTART] Ensuring Bluetooth directory exists... Apr 12 21:05:05 volumio sudo[2697]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Apr 12 21:05:05 volumio sudo[2697]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:05 volumio sudo[2697]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:05 volumio sudo[2699]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Apr 12 21:05:05 volumio sudo[2699]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:05 volumio sudo[2699]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:05 volumio volumiobt[2701]: INFO [BTSTART] Powering on Bluetooth if needed... Apr 12 21:05:05 volumio volumiobt[2704]: No default controller available Apr 12 21:05:06 volumio volumiobt[2706]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Apr 12 21:05:06 volumio volumiobt[2707]: [83B blob data] Apr 12 21:05:06 volumio volumiobt[2707]: No default controller available Apr 12 21:05:06 volumio volumiobt[2707]: [bluetoothctl]> pairable on Apr 12 21:05:06 volumio volumiobt[2707]: No default controller available Apr 12 21:05:06 volumio volumiobt[2707]: [113B blob data] Apr 12 21:05:06 volumio volumiobt[2707]: [bluetoothctl]> Apr 12 21:05:06 volumio volumiobt[2708]: INFO [BTSTART] Registering Bluetooth agent... Apr 12 21:05:06 volumio volumiobt[2710]: No agent is registered Apr 12 21:05:06 volumio volumiobt[2711]: INFO [BTSTART] Agent registered successfully. Apr 12 21:05:06 volumio volumiobt[2712]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Apr 12 21:05:07 volumio volumiobt[2713]: 2026-04-12 21:05:07 a2dp-agent [INFO] Connecting to system D-Bus Apr 12 21:05:07 volumio volumiobt[2713]: 2026-04-12 21:05:07 a2dp-agent [INFO] Connected to system D-Bus Apr 12 21:05:07 volumio volumiobt[2713]: 2026-04-12 21:05:07 a2dp-agent [ERROR] No Bluetooth adapter found: Bluetooth adapter not found Apr 12 21:05:07 volumio volumiobt[2713]: 2026-04-12 21:05:07 a2dp-agent [ERROR] Agent crashed: Bluetooth adapter not found Apr 12 21:05:07 volumio volumiobt[2713]: Traceback (most recent call last): Apr 12 21:05:07 volumio volumiobt[2713]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:07 volumio volumiobt[2713]: asyncio.run(_run()) Apr 12 21:05:07 volumio volumiobt[2713]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:07 volumio volumiobt[2713]: return runner.run(main) Apr 12 21:05:07 volumio volumiobt[2713]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:07 volumio volumiobt[2713]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:07 volumio volumiobt[2713]: return self._loop.run_until_complete(task) Apr 12 21:05:07 volumio volumiobt[2713]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:07 volumio volumiobt[2713]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:07 volumio volumiobt[2713]: return future.result() Apr 12 21:05:07 volumio volumiobt[2713]: ^^^^^^^^^^^^^^^ Apr 12 21:05:07 volumio volumiobt[2713]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:07 volumio volumiobt[2713]: adapter_path = await find_adapter(bus) Apr 12 21:05:07 volumio volumiobt[2713]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:07 volumio volumiobt[2713]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:07 volumio volumiobt[2713]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:07 volumio volumiobt[2713]: Exception: Bluetooth adapter not found Apr 12 21:05:07 volumio volumiobt[2713]: Traceback (most recent call last): Apr 12 21:05:07 volumio volumiobt[2713]: File "/bin/bt/a2dp-agent", line 234, in Apr 12 21:05:07 volumio volumiobt[2713]: main() Apr 12 21:05:07 volumio volumiobt[2713]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:07 volumio volumiobt[2713]: asyncio.run(_run()) Apr 12 21:05:07 volumio volumiobt[2713]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:07 volumio volumiobt[2713]: return runner.run(main) Apr 12 21:05:07 volumio volumiobt[2713]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:07 volumio volumiobt[2713]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:07 volumio volumiobt[2713]: return self._loop.run_until_complete(task) Apr 12 21:05:07 volumio volumiobt[2713]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:07 volumio volumiobt[2713]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:07 volumio volumiobt[2713]: return future.result() Apr 12 21:05:07 volumio volumiobt[2713]: ^^^^^^^^^^^^^^^ Apr 12 21:05:07 volumio volumiobt[2713]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:07 volumio volumiobt[2713]: adapter_path = await find_adapter(bus) Apr 12 21:05:07 volumio volumiobt[2713]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:07 volumio volumiobt[2713]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:07 volumio volumiobt[2713]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:07 volumio volumiobt[2713]: Exception: Bluetooth adapter not found Apr 12 21:05:08 volumio systemd[1]: volumiobt.service: Main process exited, code=exited, status=1/FAILURE Apr 12 21:05:08 volumio systemd[1]: volumiobt.service: Failed with result 'exit-code'. Apr 12 21:05:08 volumio systemd[1]: volumiobt.service: Consumed 1.659s CPU time. Apr 12 21:05:08 volumio systemd[1]: volumiobt.service: Scheduled restart job, restart counter is at 2. Apr 12 21:05:08 volumio systemd[1]: Stopped volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:08 volumio systemd[1]: volumiobt.service: Consumed 1.659s CPU time. Apr 12 21:05:08 volumio systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:08 volumio volumiobt[2715]: INFO [BTSTART] Ensuring Bluetooth directory exists... Apr 12 21:05:08 volumio sudo[2716]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Apr 12 21:05:08 volumio sudo[2716]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:08 volumio sudo[2716]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:08 volumio sudo[2718]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Apr 12 21:05:08 volumio sudo[2718]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:08 volumio sudo[2718]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:08 volumio volumiobt[2720]: INFO [BTSTART] Powering on Bluetooth if needed... Apr 12 21:05:08 volumio volumiobt[2723]: No default controller available Apr 12 21:05:09 volumio volumiobt[2725]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Apr 12 21:05:09 volumio volumiobt[2726]: [83B blob data] Apr 12 21:05:09 volumio volumiobt[2726]: No default controller available Apr 12 21:05:09 volumio volumiobt[2726]: [bluetoothctl]> pairable on Apr 12 21:05:09 volumio volumiobt[2726]: No default controller available Apr 12 21:05:09 volumio volumiobt[2726]: [bluetoothctl]> Apr 12 21:05:09 volumio volumiobt[2731]: INFO [BTSTART] Registering Bluetooth agent... Apr 12 21:05:09 volumio volumiobt[2743]: No agent is registered Apr 12 21:05:09 volumio volumiobt[2744]: INFO [BTSTART] Agent registered successfully. Apr 12 21:05:09 volumio volumiobt[2745]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Apr 12 21:05:10 volumio volumiobt[2746]: 2026-04-12 21:05:10 a2dp-agent [INFO] Connecting to system D-Bus Apr 12 21:05:10 volumio volumiobt[2746]: 2026-04-12 21:05:10 a2dp-agent [INFO] Connected to system D-Bus Apr 12 21:05:10 volumio volumiobt[2746]: 2026-04-12 21:05:10 a2dp-agent [ERROR] No Bluetooth adapter found: Bluetooth adapter not found Apr 12 21:05:10 volumio volumiobt[2746]: 2026-04-12 21:05:10 a2dp-agent [ERROR] Agent crashed: Bluetooth adapter not found Apr 12 21:05:10 volumio volumiobt[2746]: Traceback (most recent call last): Apr 12 21:05:10 volumio volumiobt[2746]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:10 volumio volumiobt[2746]: asyncio.run(_run()) Apr 12 21:05:10 volumio volumiobt[2746]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:10 volumio volumiobt[2746]: return runner.run(main) Apr 12 21:05:10 volumio volumiobt[2746]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:10 volumio volumiobt[2746]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:10 volumio volumiobt[2746]: return self._loop.run_until_complete(task) Apr 12 21:05:10 volumio volumiobt[2746]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:10 volumio volumiobt[2746]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:10 volumio volumiobt[2746]: return future.result() Apr 12 21:05:10 volumio volumiobt[2746]: ^^^^^^^^^^^^^^^ Apr 12 21:05:10 volumio volumiobt[2746]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:10 volumio volumiobt[2746]: adapter_path = await find_adapter(bus) Apr 12 21:05:10 volumio volumiobt[2746]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:10 volumio volumiobt[2746]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:10 volumio volumiobt[2746]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:10 volumio volumiobt[2746]: Exception: Bluetooth adapter not found Apr 12 21:05:10 volumio volumiobt[2746]: Traceback (most recent call last): Apr 12 21:05:10 volumio volumiobt[2746]: File "/bin/bt/a2dp-agent", line 234, in Apr 12 21:05:10 volumio volumiobt[2746]: main() Apr 12 21:05:10 volumio volumiobt[2746]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:10 volumio volumiobt[2746]: asyncio.run(_run()) Apr 12 21:05:10 volumio volumiobt[2746]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:10 volumio volumiobt[2746]: return runner.run(main) Apr 12 21:05:10 volumio volumiobt[2746]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:10 volumio volumiobt[2746]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:10 volumio volumiobt[2746]: return self._loop.run_until_complete(task) Apr 12 21:05:10 volumio volumiobt[2746]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:10 volumio volumiobt[2746]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:10 volumio volumiobt[2746]: return future.result() Apr 12 21:05:10 volumio volumiobt[2746]: ^^^^^^^^^^^^^^^ Apr 12 21:05:10 volumio volumiobt[2746]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:10 volumio volumiobt[2746]: adapter_path = await find_adapter(bus) Apr 12 21:05:10 volumio volumiobt[2746]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:10 volumio volumiobt[2746]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:10 volumio volumiobt[2746]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:10 volumio volumiobt[2746]: Exception: Bluetooth adapter not found Apr 12 21:05:11 volumio systemd[1]: volumiobt.service: Main process exited, code=exited, status=1/FAILURE Apr 12 21:05:11 volumio systemd[1]: volumiobt.service: Failed with result 'exit-code'. Apr 12 21:05:11 volumio systemd[1]: volumiobt.service: Consumed 1.657s CPU time. Apr 12 21:05:11 volumio systemd[1]: volumiobt.service: Scheduled restart job, restart counter is at 3. Apr 12 21:05:11 volumio systemd[1]: Stopped volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:11 volumio systemd[1]: volumiobt.service: Consumed 1.657s CPU time. Apr 12 21:05:11 volumio systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:11 volumio volumiobt[2748]: INFO [BTSTART] Ensuring Bluetooth directory exists... Apr 12 21:05:11 volumio sudo[2749]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Apr 12 21:05:11 volumio sudo[2749]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:11 volumio sudo[2749]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:11 volumio sudo[2751]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Apr 12 21:05:11 volumio sudo[2751]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:11 volumio sudo[2751]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:11 volumio volumiobt[2753]: INFO [BTSTART] Powering on Bluetooth if needed... Apr 12 21:05:11 volumio volumiobt[2756]: No default controller available Apr 12 21:05:12 volumio volumiobt[2759]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Apr 12 21:05:12 volumio volumiobt[2760]: [83B blob data] Apr 12 21:05:12 volumio volumiobt[2760]: No default controller available Apr 12 21:05:12 volumio volumiobt[2760]: [bluetoothctl]> pairable on Apr 12 21:05:12 volumio volumiobt[2760]: No default controller available Apr 12 21:05:12 volumio volumiobt[2760]: [bluetoothctl]> Apr 12 21:05:12 volumio volumiobt[2761]: INFO [BTSTART] Registering Bluetooth agent... Apr 12 21:05:12 volumio volumiobt[2763]: No agent is registered Apr 12 21:05:12 volumio volumiobt[2764]: INFO [BTSTART] Agent registered successfully. Apr 12 21:05:12 volumio volumiobt[2765]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Apr 12 21:05:13 volumio volumiobt[2766]: 2026-04-12 21:05:13 a2dp-agent [INFO] Connecting to system D-Bus Apr 12 21:05:13 volumio volumiobt[2766]: 2026-04-12 21:05:13 a2dp-agent [INFO] Connected to system D-Bus Apr 12 21:05:13 volumio volumiobt[2766]: 2026-04-12 21:05:13 a2dp-agent [ERROR] No Bluetooth adapter found: Bluetooth adapter not found Apr 12 21:05:13 volumio volumiobt[2766]: 2026-04-12 21:05:13 a2dp-agent [ERROR] Agent crashed: Bluetooth adapter not found Apr 12 21:05:13 volumio volumiobt[2766]: Traceback (most recent call last): Apr 12 21:05:13 volumio volumiobt[2766]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:13 volumio volumiobt[2766]: asyncio.run(_run()) Apr 12 21:05:13 volumio volumiobt[2766]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:13 volumio volumiobt[2766]: return runner.run(main) Apr 12 21:05:13 volumio volumiobt[2766]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:13 volumio volumiobt[2766]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:13 volumio volumiobt[2766]: return self._loop.run_until_complete(task) Apr 12 21:05:13 volumio volumiobt[2766]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:13 volumio volumiobt[2766]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:13 volumio volumiobt[2766]: return future.result() Apr 12 21:05:13 volumio volumiobt[2766]: ^^^^^^^^^^^^^^^ Apr 12 21:05:13 volumio volumiobt[2766]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:13 volumio volumiobt[2766]: adapter_path = await find_adapter(bus) Apr 12 21:05:13 volumio volumiobt[2766]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:13 volumio volumiobt[2766]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:13 volumio volumiobt[2766]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:13 volumio volumiobt[2766]: Exception: Bluetooth adapter not found Apr 12 21:05:13 volumio volumiobt[2766]: Traceback (most recent call last): Apr 12 21:05:13 volumio volumiobt[2766]: File "/bin/bt/a2dp-agent", line 234, in Apr 12 21:05:13 volumio volumiobt[2766]: main() Apr 12 21:05:13 volumio volumiobt[2766]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:13 volumio volumiobt[2766]: asyncio.run(_run()) Apr 12 21:05:13 volumio volumiobt[2766]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:13 volumio volumiobt[2766]: return runner.run(main) Apr 12 21:05:13 volumio volumiobt[2766]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:13 volumio volumiobt[2766]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:13 volumio volumiobt[2766]: return self._loop.run_until_complete(task) Apr 12 21:05:13 volumio volumiobt[2766]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:13 volumio volumiobt[2766]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:13 volumio volumiobt[2766]: return future.result() Apr 12 21:05:13 volumio volumiobt[2766]: ^^^^^^^^^^^^^^^ Apr 12 21:05:13 volumio volumiobt[2766]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:13 volumio volumiobt[2766]: adapter_path = await find_adapter(bus) Apr 12 21:05:13 volumio volumiobt[2766]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:13 volumio volumiobt[2766]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:13 volumio volumiobt[2766]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:13 volumio volumiobt[2766]: Exception: Bluetooth adapter not found Apr 12 21:05:14 volumio systemd[1]: volumiobt.service: Main process exited, code=exited, status=1/FAILURE Apr 12 21:05:14 volumio systemd[1]: volumiobt.service: Failed with result 'exit-code'. Apr 12 21:05:14 volumio systemd[1]: volumiobt.service: Consumed 1.660s CPU time. Apr 12 21:05:14 volumio systemd[1]: volumiobt.service: Scheduled restart job, restart counter is at 4. Apr 12 21:05:14 volumio systemd[1]: Stopped volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:14 volumio systemd[1]: volumiobt.service: Consumed 1.660s CPU time. Apr 12 21:05:14 volumio systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:14 volumio volumiobt[2768]: INFO [BTSTART] Ensuring Bluetooth directory exists... Apr 12 21:05:14 volumio sudo[2769]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Apr 12 21:05:14 volumio sudo[2769]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:14 volumio sudo[2769]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:14 volumio sudo[2771]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Apr 12 21:05:14 volumio sudo[2771]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:14 volumio sudo[2771]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:14 volumio volumiobt[2773]: INFO [BTSTART] Powering on Bluetooth if needed... Apr 12 21:05:14 volumio volumiobt[2776]: No default controller available Apr 12 21:05:15 volumio volumiobt[2778]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Apr 12 21:05:15 volumio volumiobt[2779]: [83B blob data] Apr 12 21:05:15 volumio volumiobt[2779]: No default controller available Apr 12 21:05:15 volumio volumiobt[2779]: [bluetoothctl]> pairable on Apr 12 21:05:15 volumio volumiobt[2779]: No default controller available Apr 12 21:05:15 volumio volumiobt[2779]: [113B blob data] Apr 12 21:05:15 volumio volumiobt[2779]: [bluetoothctl]> Apr 12 21:05:15 volumio volumiobt[2780]: INFO [BTSTART] Registering Bluetooth agent... Apr 12 21:05:15 volumio volumiobt[2782]: No agent is registered Apr 12 21:05:15 volumio volumiobt[2783]: INFO [BTSTART] Agent registered successfully. Apr 12 21:05:15 volumio volumiobt[2784]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Apr 12 21:05:16 volumio volumiobt[2785]: 2026-04-12 21:05:16 a2dp-agent [INFO] Connecting to system D-Bus Apr 12 21:05:16 volumio volumiobt[2785]: 2026-04-12 21:05:16 a2dp-agent [INFO] Connected to system D-Bus Apr 12 21:05:16 volumio volumiobt[2785]: 2026-04-12 21:05:16 a2dp-agent [ERROR] No Bluetooth adapter found: Bluetooth adapter not found Apr 12 21:05:16 volumio volumiobt[2785]: 2026-04-12 21:05:16 a2dp-agent [ERROR] Agent crashed: Bluetooth adapter not found Apr 12 21:05:16 volumio volumiobt[2785]: Traceback (most recent call last): Apr 12 21:05:16 volumio volumiobt[2785]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:16 volumio volumiobt[2785]: asyncio.run(_run()) Apr 12 21:05:16 volumio volumiobt[2785]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:16 volumio volumiobt[2785]: return runner.run(main) Apr 12 21:05:16 volumio volumiobt[2785]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:16 volumio volumiobt[2785]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:16 volumio volumiobt[2785]: return self._loop.run_until_complete(task) Apr 12 21:05:16 volumio volumiobt[2785]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:16 volumio volumiobt[2785]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:16 volumio volumiobt[2785]: return future.result() Apr 12 21:05:16 volumio volumiobt[2785]: ^^^^^^^^^^^^^^^ Apr 12 21:05:16 volumio volumiobt[2785]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:16 volumio volumiobt[2785]: adapter_path = await find_adapter(bus) Apr 12 21:05:16 volumio volumiobt[2785]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:16 volumio volumiobt[2785]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:16 volumio volumiobt[2785]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:16 volumio volumiobt[2785]: Exception: Bluetooth adapter not found Apr 12 21:05:16 volumio volumiobt[2785]: Traceback (most recent call last): Apr 12 21:05:16 volumio volumiobt[2785]: File "/bin/bt/a2dp-agent", line 234, in Apr 12 21:05:16 volumio volumiobt[2785]: main() Apr 12 21:05:16 volumio volumiobt[2785]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:16 volumio volumiobt[2785]: asyncio.run(_run()) Apr 12 21:05:16 volumio volumiobt[2785]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:16 volumio volumiobt[2785]: return runner.run(main) Apr 12 21:05:16 volumio volumiobt[2785]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:16 volumio volumiobt[2785]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:16 volumio volumiobt[2785]: return self._loop.run_until_complete(task) Apr 12 21:05:16 volumio volumiobt[2785]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:16 volumio volumiobt[2785]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:16 volumio volumiobt[2785]: return future.result() Apr 12 21:05:16 volumio volumiobt[2785]: ^^^^^^^^^^^^^^^ Apr 12 21:05:16 volumio volumiobt[2785]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:16 volumio volumiobt[2785]: adapter_path = await find_adapter(bus) Apr 12 21:05:16 volumio volumiobt[2785]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:16 volumio volumiobt[2785]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:16 volumio volumiobt[2785]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:16 volumio volumiobt[2785]: Exception: Bluetooth adapter not found Apr 12 21:05:17 volumio volumio[1151]: verbose: New Socket.io Connection to 192.168.1.147 from 192.168.1.138 UA: Mozilla/5.0 (Android 15; Mobile; rv:149.0) Gecko/149.0 Firefox/149.0 Engine version: 3 Transport: polling Total Clients: 8 Apr 12 21:05:17 volumio systemd[1]: volumiobt.service: Main process exited, code=exited, status=1/FAILURE Apr 12 21:05:17 volumio systemd[1]: volumiobt.service: Failed with result 'exit-code'. Apr 12 21:05:17 volumio systemd[1]: volumiobt.service: Consumed 1.679s CPU time. Apr 12 21:05:17 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 12 21:05:17 volumio systemd[1]: volumiobt.service: Scheduled restart job, restart counter is at 5. Apr 12 21:05:17 volumio systemd[1]: Stopped volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:17 volumio systemd[1]: volumiobt.service: Consumed 1.679s CPU time. Apr 12 21:05:17 volumio volumio[1151]: info: CoreCommandRouter::volumioGetVisibleSources Apr 12 21:05:17 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 21:05:17 volumio volumio[1151]: info: CoreCommandRouter::volumioGetState Apr 12 21:05:17 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:05:17 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 12 21:05:17 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 12 21:05:17 volumio volumio[1151]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Apr 12 21:05:17 volumio volumio[1151]: info: Received Get System Info Apr 12 21:05:17 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 21:05:17 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 21:05:17 volumio volumio[1151]: info: Discovery: Getting this device information Apr 12 21:05:17 volumio volumio[1151]: info: CoreCommandRouter::volumioGetState Apr 12 21:05:17 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:05:17 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 21:05:17 volumio volumio[1151]: info: CoreCommandRouter::volumioGetState Apr 12 21:05:17 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:05:17 volumio systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:17 volumio volumio[1151]: info: Listing playlists Apr 12 21:05:17 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 12 21:05:17 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 12 21:05:17 volumio volumiobt[2787]: INFO [BTSTART] Ensuring Bluetooth directory exists... Apr 12 21:05:17 volumio sudo[2788]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Apr 12 21:05:17 volumio sudo[2788]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:17 volumio sudo[2788]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:17 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 12 21:05:17 volumio sudo[2790]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Apr 12 21:05:17 volumio sudo[2790]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:17 volumio sudo[2790]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:17 volumio volumiobt[2792]: INFO [BTSTART] Powering on Bluetooth if needed... Apr 12 21:05:17 volumio volumiobt[2795]: No default controller available Apr 12 21:05:18 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 12 21:05:18 volumio volumio[1151]: info: Received Get System Info Apr 12 21:05:18 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 21:05:18 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 21:05:18 volumio volumio[1151]: info: Discovery: Getting this device information Apr 12 21:05:18 volumio volumio[1151]: info: CoreCommandRouter::volumioGetState Apr 12 21:05:18 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:05:18 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 21:05:18 volumio volumiobt[2800]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Apr 12 21:05:18 volumio volumiobt[2801]: [83B blob data] Apr 12 21:05:18 volumio volumiobt[2801]: No default controller available Apr 12 21:05:18 volumio volumiobt[2801]: [bluetoothctl]> pairable on Apr 12 21:05:18 volumio volumiobt[2801]: No default controller available Apr 12 21:05:18 volumio volumiobt[2801]: [113B blob data] Apr 12 21:05:18 volumio volumiobt[2801]: [bluetoothctl]> Apr 12 21:05:18 volumio volumiobt[2802]: INFO [BTSTART] Registering Bluetooth agent... Apr 12 21:05:19 volumio volumiobt[2804]: No agent is registered Apr 12 21:05:19 volumio volumiobt[2805]: INFO [BTSTART] Agent registered successfully. Apr 12 21:05:19 volumio volumiobt[2806]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Apr 12 21:05:19 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Apr 12 21:05:20 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 12 21:05:20 volumio volumio[1151]: info: Received Get System Info Apr 12 21:05:20 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 21:05:20 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 21:05:20 volumio volumio[1151]: info: Discovery: Getting this device information Apr 12 21:05:20 volumio volumio[1151]: info: CoreCommandRouter::volumioGetState Apr 12 21:05:20 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:05:20 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 21:05:20 volumio volumiobt[2807]: 2026-04-12 21:05:20 a2dp-agent [INFO] Connecting to system D-Bus Apr 12 21:05:20 volumio volumiobt[2807]: 2026-04-12 21:05:20 a2dp-agent [INFO] Connected to system D-Bus Apr 12 21:05:20 volumio volumiobt[2807]: 2026-04-12 21:05:20 a2dp-agent [ERROR] No Bluetooth adapter found: Bluetooth adapter not found Apr 12 21:05:20 volumio volumiobt[2807]: 2026-04-12 21:05:20 a2dp-agent [ERROR] Agent crashed: Bluetooth adapter not found Apr 12 21:05:20 volumio volumiobt[2807]: Traceback (most recent call last): Apr 12 21:05:20 volumio volumiobt[2807]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:20 volumio volumiobt[2807]: asyncio.run(_run()) Apr 12 21:05:20 volumio volumiobt[2807]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:20 volumio volumiobt[2807]: return runner.run(main) Apr 12 21:05:20 volumio volumiobt[2807]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:20 volumio volumiobt[2807]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:20 volumio volumiobt[2807]: return self._loop.run_until_complete(task) Apr 12 21:05:20 volumio volumiobt[2807]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:20 volumio volumiobt[2807]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:20 volumio volumiobt[2807]: return future.result() Apr 12 21:05:20 volumio volumiobt[2807]: ^^^^^^^^^^^^^^^ Apr 12 21:05:20 volumio volumiobt[2807]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:20 volumio volumiobt[2807]: adapter_path = await find_adapter(bus) Apr 12 21:05:20 volumio volumiobt[2807]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:20 volumio volumiobt[2807]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:20 volumio volumiobt[2807]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:20 volumio volumiobt[2807]: Exception: Bluetooth adapter not found Apr 12 21:05:20 volumio volumiobt[2807]: Traceback (most recent call last): Apr 12 21:05:20 volumio volumiobt[2807]: File "/bin/bt/a2dp-agent", line 234, in Apr 12 21:05:20 volumio volumiobt[2807]: main() Apr 12 21:05:20 volumio volumiobt[2807]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:20 volumio volumiobt[2807]: asyncio.run(_run()) Apr 12 21:05:20 volumio volumiobt[2807]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:20 volumio volumiobt[2807]: return runner.run(main) Apr 12 21:05:20 volumio volumiobt[2807]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:20 volumio volumiobt[2807]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:20 volumio volumiobt[2807]: return self._loop.run_until_complete(task) Apr 12 21:05:20 volumio volumiobt[2807]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:20 volumio volumiobt[2807]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:20 volumio volumiobt[2807]: return future.result() Apr 12 21:05:20 volumio volumiobt[2807]: ^^^^^^^^^^^^^^^ Apr 12 21:05:20 volumio volumiobt[2807]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:20 volumio volumiobt[2807]: adapter_path = await find_adapter(bus) Apr 12 21:05:20 volumio volumiobt[2807]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:20 volumio volumiobt[2807]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:20 volumio volumiobt[2807]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:20 volumio volumiobt[2807]: Exception: Bluetooth adapter not found Apr 12 21:05:20 volumio systemd[1]: volumiobt.service: Main process exited, code=exited, status=1/FAILURE Apr 12 21:05:20 volumio systemd[1]: volumiobt.service: Failed with result 'exit-code'. Apr 12 21:05:20 volumio systemd[1]: volumiobt.service: Consumed 1.721s CPU time. Apr 12 21:05:20 volumio systemd[1]: volumiobt.service: Scheduled restart job, restart counter is at 6. Apr 12 21:05:20 volumio systemd[1]: Stopped volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:20 volumio systemd[1]: volumiobt.service: Consumed 1.721s CPU time. Apr 12 21:05:20 volumio systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:20 volumio sudo[2826]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 12 21:05:20 volumio sudo[2826]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:20 volumio volumiobt[2828]: INFO [BTSTART] Ensuring Bluetooth directory exists... Apr 12 21:05:20 volumio sudo[2827]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 12 21:05:20 volumio sudo[2827]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:20 volumio sudo[2826]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:20 volumio sudo[2827]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:20 volumio sudo[2829]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Apr 12 21:05:20 volumio sudo[2829]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:20 volumio sudo[2829]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:20 volumio volumio[1151]: verbose: New Socket.io Connection to 192.168.1.147 from 192.168.1.138 UA: Mozilla/5.0 (Android 15; Mobile; rv:149.0) Gecko/149.0 Firefox/149.0 Engine version: 3 Transport: polling Total Clients: 9 Apr 12 21:05:20 volumio sudo[2833]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Apr 12 21:05:20 volumio sudo[2833]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:21 volumio sudo[2833]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:21 volumio volumiobt[2835]: INFO [BTSTART] Powering on Bluetooth if needed... Apr 12 21:05:21 volumio volumiobt[2838]: No default controller available Apr 12 21:05:21 volumio volumio[1151]: info: Received Get System Info Apr 12 21:05:21 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 21:05:21 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 21:05:21 volumio volumio[1151]: info: Discovery: Getting this device information Apr 12 21:05:21 volumio volumio[1151]: info: CoreCommandRouter::volumioGetState Apr 12 21:05:21 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:05:21 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 21:05:21 volumio volumio[1151]: info: CoreCommandRouter::volumioGetState Apr 12 21:05:21 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:05:21 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 12 21:05:21 volumio volumio[1151]: info: CoreCommandRouter::volumioGetVisibleSources Apr 12 21:05:21 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 21:05:21 volumio volumio[1151]: info: CoreCommandRouter::volumioGetState Apr 12 21:05:21 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:05:21 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 12 21:05:21 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 12 21:05:21 volumio volumio[1151]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Apr 12 21:05:21 volumio volumio[1151]: info: Received Get System Info Apr 12 21:05:21 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 21:05:21 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 21:05:21 volumio volumio[1151]: info: Discovery: Getting this device information Apr 12 21:05:21 volumio volumio[1151]: info: CoreCommandRouter::volumioGetState Apr 12 21:05:21 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:05:21 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 21:05:21 volumio volumio[1151]: info: CoreCommandRouter::volumioGetState Apr 12 21:05:21 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:05:21 volumio volumio[1151]: info: Listing playlists Apr 12 21:05:21 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 12 21:05:22 volumio volumiobt[2840]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Apr 12 21:05:22 volumio volumiobt[2841]: [83B blob data] Apr 12 21:05:22 volumio volumiobt[2841]: No default controller available Apr 12 21:05:22 volumio volumiobt[2841]: [bluetoothctl]> pairable on Apr 12 21:05:22 volumio volumiobt[2841]: No default controller available Apr 12 21:05:22 volumio volumiobt[2841]: [bluetoothctl]> Apr 12 21:05:22 volumio volumiobt[2842]: INFO [BTSTART] Registering Bluetooth agent... Apr 12 21:05:22 volumio volumiobt[2844]: No agent is registered Apr 12 21:05:22 volumio volumiobt[2845]: INFO [BTSTART] Agent registered successfully. Apr 12 21:05:22 volumio volumiobt[2846]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Apr 12 21:05:23 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 12 21:05:23 volumio volumio[1151]: info: Received Get System Info Apr 12 21:05:23 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 21:05:23 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 21:05:23 volumio volumio[1151]: info: Discovery: Getting this device information Apr 12 21:05:23 volumio volumio[1151]: info: CoreCommandRouter::volumioGetState Apr 12 21:05:23 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:05:23 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 21:05:23 volumio volumiobt[2847]: 2026-04-12 21:05:23 a2dp-agent [INFO] Connecting to system D-Bus Apr 12 21:05:23 volumio volumiobt[2847]: 2026-04-12 21:05:23 a2dp-agent [INFO] Connected to system D-Bus Apr 12 21:05:23 volumio volumiobt[2847]: 2026-04-12 21:05:23 a2dp-agent [ERROR] No Bluetooth adapter found: Bluetooth adapter not found Apr 12 21:05:23 volumio volumiobt[2847]: 2026-04-12 21:05:23 a2dp-agent [ERROR] Agent crashed: Bluetooth adapter not found Apr 12 21:05:23 volumio volumiobt[2847]: Traceback (most recent call last): Apr 12 21:05:23 volumio volumiobt[2847]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:23 volumio volumiobt[2847]: asyncio.run(_run()) Apr 12 21:05:23 volumio volumiobt[2847]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:23 volumio volumiobt[2847]: return runner.run(main) Apr 12 21:05:23 volumio volumiobt[2847]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:23 volumio volumiobt[2847]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:23 volumio volumiobt[2847]: return self._loop.run_until_complete(task) Apr 12 21:05:23 volumio volumiobt[2847]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:23 volumio volumiobt[2847]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:23 volumio volumiobt[2847]: return future.result() Apr 12 21:05:23 volumio volumiobt[2847]: ^^^^^^^^^^^^^^^ Apr 12 21:05:23 volumio volumiobt[2847]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:23 volumio volumiobt[2847]: adapter_path = await find_adapter(bus) Apr 12 21:05:23 volumio volumiobt[2847]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:23 volumio volumiobt[2847]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:23 volumio volumiobt[2847]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:23 volumio volumiobt[2847]: Exception: Bluetooth adapter not found Apr 12 21:05:23 volumio volumiobt[2847]: Traceback (most recent call last): Apr 12 21:05:23 volumio volumiobt[2847]: File "/bin/bt/a2dp-agent", line 234, in Apr 12 21:05:23 volumio volumiobt[2847]: main() Apr 12 21:05:23 volumio volumiobt[2847]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:23 volumio volumiobt[2847]: asyncio.run(_run()) Apr 12 21:05:23 volumio volumiobt[2847]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:23 volumio volumiobt[2847]: return runner.run(main) Apr 12 21:05:23 volumio volumiobt[2847]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:23 volumio volumiobt[2847]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:23 volumio volumiobt[2847]: return self._loop.run_until_complete(task) Apr 12 21:05:23 volumio volumiobt[2847]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:23 volumio volumiobt[2847]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:23 volumio volumiobt[2847]: return future.result() Apr 12 21:05:23 volumio volumiobt[2847]: ^^^^^^^^^^^^^^^ Apr 12 21:05:23 volumio volumiobt[2847]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:23 volumio volumiobt[2847]: adapter_path = await find_adapter(bus) Apr 12 21:05:23 volumio volumiobt[2847]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:23 volumio volumiobt[2847]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:23 volumio volumiobt[2847]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:23 volumio volumiobt[2847]: Exception: Bluetooth adapter not found Apr 12 21:05:23 volumio systemd[1]: volumiobt.service: Main process exited, code=exited, status=1/FAILURE Apr 12 21:05:23 volumio systemd[1]: volumiobt.service: Failed with result 'exit-code'. Apr 12 21:05:23 volumio systemd[1]: volumiobt.service: Consumed 1.694s CPU time. Apr 12 21:05:23 volumio systemd[1]: volumiobt.service: Scheduled restart job, restart counter is at 7. Apr 12 21:05:23 volumio systemd[1]: Stopped volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:23 volumio systemd[1]: volumiobt.service: Consumed 1.694s CPU time. Apr 12 21:05:24 volumio systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:24 volumio volumiobt[2849]: INFO [BTSTART] Ensuring Bluetooth directory exists... Apr 12 21:05:24 volumio sudo[2850]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Apr 12 21:05:24 volumio sudo[2850]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:24 volumio sudo[2850]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:24 volumio sudo[2852]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Apr 12 21:05:24 volumio sudo[2852]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:24 volumio sudo[2852]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:24 volumio volumiobt[2854]: INFO [BTSTART] Powering on Bluetooth if needed... Apr 12 21:05:24 volumio volumiobt[2857]: No default controller available Apr 12 21:05:24 volumio sudo[2860]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 12 21:05:24 volumio sudo[2860]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:24 volumio sudo[2860]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:24 volumio sudo[2862]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 12 21:05:24 volumio sudo[2862]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:24 volumio sudo[2862]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:24 volumio volumio[1151]: verbose: New Socket.io Connection to 192.168.1.147 from 192.168.1.138 UA: Mozilla/5.0 (Android 15; Mobile; rv:149.0) Gecko/149.0 Firefox/149.0 Engine version: 3 Transport: polling Total Clients: 9 Apr 12 21:05:24 volumio volumio[1151]: info: Received Get System Info Apr 12 21:05:24 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 21:05:24 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 21:05:24 volumio volumio[1151]: info: Discovery: Getting this device information Apr 12 21:05:24 volumio volumio[1151]: info: CoreCommandRouter::volumioGetState Apr 12 21:05:24 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:05:24 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 21:05:24 volumio volumio[1151]: info: CoreCommandRouter::volumioGetState Apr 12 21:05:24 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:05:24 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 12 21:05:24 volumio volumio[1151]: info: CoreCommandRouter::volumioGetVisibleSources Apr 12 21:05:24 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 21:05:24 volumio volumio[1151]: info: CoreCommandRouter::volumioGetState Apr 12 21:05:24 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:05:25 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 12 21:05:25 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 12 21:05:25 volumio volumio[1151]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Apr 12 21:05:25 volumio volumio[1151]: info: Received Get System Info Apr 12 21:05:25 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 21:05:25 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 21:05:25 volumio volumio[1151]: info: Discovery: Getting this device information Apr 12 21:05:25 volumio volumio[1151]: info: CoreCommandRouter::volumioGetState Apr 12 21:05:25 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:05:25 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 21:05:25 volumio volumio[1151]: info: CoreCommandRouter::volumioGetState Apr 12 21:05:25 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:05:25 volumio volumio[1151]: info: Listing playlists Apr 12 21:05:25 volumio volumio[1151]: info: Received Get System Info Apr 12 21:05:25 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 21:05:25 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 21:05:25 volumio volumio[1151]: info: Discovery: Getting this device information Apr 12 21:05:25 volumio volumio[1151]: info: CoreCommandRouter::volumioGetState Apr 12 21:05:25 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:05:25 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 21:05:25 volumio volumio[1151]: info: CoreCommandRouter::volumioGetState Apr 12 21:05:25 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:05:25 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 12 21:05:25 volumio volumiobt[2865]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Apr 12 21:05:25 volumio volumiobt[2866]: [83B blob data] Apr 12 21:05:25 volumio volumiobt[2866]: No default controller available Apr 12 21:05:25 volumio volumiobt[2866]: [bluetoothctl]> pairable on Apr 12 21:05:25 volumio volumiobt[2866]: No default controller available Apr 12 21:05:25 volumio volumiobt[2866]: [113B blob data] Apr 12 21:05:25 volumio volumiobt[2866]: [bluetoothctl]> Apr 12 21:05:25 volumio volumiobt[2867]: INFO [BTSTART] Registering Bluetooth agent... Apr 12 21:05:25 volumio volumiobt[2869]: No agent is registered Apr 12 21:05:25 volumio volumiobt[2870]: INFO [BTSTART] Agent registered successfully. Apr 12 21:05:25 volumio volumiobt[2871]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Apr 12 21:05:26 volumio volumio[1151]: info: CoreCommandRouter::volumioGetQueue Apr 12 21:05:26 volumio volumio[1151]: info: CoreStateMachine::getQueue Apr 12 21:05:26 volumio volumio[1151]: info: CorePlayQueue::getQueue Apr 12 21:05:26 volumio volumiobt[2872]: 2026-04-12 21:05:26 a2dp-agent [INFO] Connecting to system D-Bus Apr 12 21:05:26 volumio volumiobt[2872]: 2026-04-12 21:05:26 a2dp-agent [INFO] Connected to system D-Bus Apr 12 21:05:26 volumio volumiobt[2872]: 2026-04-12 21:05:26 a2dp-agent [ERROR] No Bluetooth adapter found: Bluetooth adapter not found Apr 12 21:05:26 volumio volumiobt[2872]: 2026-04-12 21:05:26 a2dp-agent [ERROR] Agent crashed: Bluetooth adapter not found Apr 12 21:05:26 volumio volumiobt[2872]: Traceback (most recent call last): Apr 12 21:05:26 volumio volumiobt[2872]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:26 volumio volumiobt[2872]: asyncio.run(_run()) Apr 12 21:05:26 volumio volumiobt[2872]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:26 volumio volumiobt[2872]: return runner.run(main) Apr 12 21:05:26 volumio volumiobt[2872]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:26 volumio volumiobt[2872]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:26 volumio volumiobt[2872]: return self._loop.run_until_complete(task) Apr 12 21:05:26 volumio volumiobt[2872]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:26 volumio volumiobt[2872]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:26 volumio volumiobt[2872]: return future.result() Apr 12 21:05:26 volumio volumiobt[2872]: ^^^^^^^^^^^^^^^ Apr 12 21:05:26 volumio volumiobt[2872]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:26 volumio volumiobt[2872]: adapter_path = await find_adapter(bus) Apr 12 21:05:26 volumio volumiobt[2872]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:26 volumio volumiobt[2872]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:26 volumio volumiobt[2872]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:26 volumio volumiobt[2872]: Exception: Bluetooth adapter not found Apr 12 21:05:26 volumio volumiobt[2872]: Traceback (most recent call last): Apr 12 21:05:26 volumio volumiobt[2872]: File "/bin/bt/a2dp-agent", line 234, in Apr 12 21:05:26 volumio volumiobt[2872]: main() Apr 12 21:05:26 volumio volumiobt[2872]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:26 volumio volumiobt[2872]: asyncio.run(_run()) Apr 12 21:05:26 volumio volumiobt[2872]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:26 volumio volumiobt[2872]: return runner.run(main) Apr 12 21:05:26 volumio volumiobt[2872]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:26 volumio volumiobt[2872]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:26 volumio volumiobt[2872]: return self._loop.run_until_complete(task) Apr 12 21:05:26 volumio volumiobt[2872]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:26 volumio volumiobt[2872]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:26 volumio volumiobt[2872]: return future.result() Apr 12 21:05:26 volumio volumiobt[2872]: ^^^^^^^^^^^^^^^ Apr 12 21:05:26 volumio volumiobt[2872]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:26 volumio volumiobt[2872]: adapter_path = await find_adapter(bus) Apr 12 21:05:26 volumio volumiobt[2872]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:26 volumio volumiobt[2872]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:26 volumio volumiobt[2872]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:26 volumio volumiobt[2872]: Exception: Bluetooth adapter not found Apr 12 21:05:26 volumio systemd[1]: volumiobt.service: Main process exited, code=exited, status=1/FAILURE Apr 12 21:05:26 volumio systemd[1]: volumiobt.service: Failed with result 'exit-code'. Apr 12 21:05:26 volumio systemd[1]: volumiobt.service: Consumed 1.650s CPU time. Apr 12 21:05:26 volumio systemd[1]: volumiobt.service: Scheduled restart job, restart counter is at 8. Apr 12 21:05:26 volumio systemd[1]: Stopped volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:26 volumio systemd[1]: volumiobt.service: Consumed 1.650s CPU time. Apr 12 21:05:27 volumio systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:27 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 12 21:05:27 volumio volumiobt[2874]: INFO [BTSTART] Ensuring Bluetooth directory exists... Apr 12 21:05:27 volumio sudo[2875]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Apr 12 21:05:27 volumio sudo[2875]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:27 volumio sudo[2875]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:27 volumio sudo[2877]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Apr 12 21:05:27 volumio sudo[2877]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:27 volumio sudo[2877]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:27 volumio volumiobt[2879]: INFO [BTSTART] Powering on Bluetooth if needed... Apr 12 21:05:27 volumio volumiobt[2882]: No default controller available Apr 12 21:05:28 volumio volumiobt[2884]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Apr 12 21:05:28 volumio volumiobt[2885]: [83B blob data] Apr 12 21:05:28 volumio volumiobt[2885]: No default controller available Apr 12 21:05:28 volumio volumiobt[2885]: [bluetoothctl]> pairable on Apr 12 21:05:28 volumio volumiobt[2885]: No default controller available Apr 12 21:05:28 volumio volumiobt[2885]: [113B blob data] Apr 12 21:05:28 volumio volumiobt[2885]: [bluetoothctl]> Apr 12 21:05:28 volumio volumiobt[2886]: INFO [BTSTART] Registering Bluetooth agent... Apr 12 21:05:28 volumio volumiobt[2888]: No agent is registered Apr 12 21:05:28 volumio volumiobt[2889]: INFO [BTSTART] Agent registered successfully. Apr 12 21:05:28 volumio volumiobt[2890]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Apr 12 21:05:29 volumio volumiobt[2891]: 2026-04-12 21:05:29 a2dp-agent [INFO] Connecting to system D-Bus Apr 12 21:05:29 volumio volumiobt[2891]: 2026-04-12 21:05:29 a2dp-agent [INFO] Connected to system D-Bus Apr 12 21:05:29 volumio volumiobt[2891]: 2026-04-12 21:05:29 a2dp-agent [ERROR] No Bluetooth adapter found: Bluetooth adapter not found Apr 12 21:05:29 volumio volumiobt[2891]: 2026-04-12 21:05:29 a2dp-agent [ERROR] Agent crashed: Bluetooth adapter not found Apr 12 21:05:29 volumio volumiobt[2891]: Traceback (most recent call last): Apr 12 21:05:29 volumio volumiobt[2891]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:29 volumio volumiobt[2891]: asyncio.run(_run()) Apr 12 21:05:29 volumio volumiobt[2891]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:29 volumio volumiobt[2891]: return runner.run(main) Apr 12 21:05:29 volumio volumiobt[2891]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:29 volumio volumiobt[2891]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:29 volumio volumiobt[2891]: return self._loop.run_until_complete(task) Apr 12 21:05:29 volumio volumiobt[2891]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:29 volumio volumiobt[2891]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:29 volumio volumiobt[2891]: return future.result() Apr 12 21:05:29 volumio volumiobt[2891]: ^^^^^^^^^^^^^^^ Apr 12 21:05:29 volumio volumiobt[2891]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:29 volumio volumiobt[2891]: adapter_path = await find_adapter(bus) Apr 12 21:05:29 volumio volumiobt[2891]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:29 volumio volumiobt[2891]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:29 volumio volumiobt[2891]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:29 volumio volumiobt[2891]: Exception: Bluetooth adapter not found Apr 12 21:05:29 volumio volumiobt[2891]: Traceback (most recent call last): Apr 12 21:05:29 volumio volumiobt[2891]: File "/bin/bt/a2dp-agent", line 234, in Apr 12 21:05:29 volumio volumiobt[2891]: main() Apr 12 21:05:29 volumio volumiobt[2891]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:29 volumio volumiobt[2891]: asyncio.run(_run()) Apr 12 21:05:29 volumio volumiobt[2891]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:29 volumio volumiobt[2891]: return runner.run(main) Apr 12 21:05:29 volumio volumiobt[2891]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:29 volumio volumiobt[2891]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:29 volumio volumiobt[2891]: return self._loop.run_until_complete(task) Apr 12 21:05:29 volumio volumiobt[2891]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:29 volumio volumiobt[2891]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:29 volumio volumiobt[2891]: return future.result() Apr 12 21:05:29 volumio volumiobt[2891]: ^^^^^^^^^^^^^^^ Apr 12 21:05:29 volumio volumiobt[2891]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:29 volumio volumiobt[2891]: adapter_path = await find_adapter(bus) Apr 12 21:05:29 volumio volumiobt[2891]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:29 volumio volumiobt[2891]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:29 volumio volumiobt[2891]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:29 volumio volumiobt[2891]: Exception: Bluetooth adapter not found Apr 12 21:05:29 volumio systemd[1]: volumiobt.service: Main process exited, code=exited, status=1/FAILURE Apr 12 21:05:29 volumio systemd[1]: volumiobt.service: Failed with result 'exit-code'. Apr 12 21:05:29 volumio systemd[1]: volumiobt.service: Consumed 1.646s CPU time. Apr 12 21:05:29 volumio systemd[1]: volumiobt.service: Scheduled restart job, restart counter is at 9. Apr 12 21:05:29 volumio systemd[1]: Stopped volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:29 volumio systemd[1]: volumiobt.service: Consumed 1.646s CPU time. Apr 12 21:05:30 volumio systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:30 volumio volumiobt[2907]: INFO [BTSTART] Ensuring Bluetooth directory exists... Apr 12 21:05:30 volumio sudo[2908]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Apr 12 21:05:30 volumio sudo[2908]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:30 volumio sudo[2908]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:30 volumio sudo[2910]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Apr 12 21:05:30 volumio sudo[2910]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:30 volumio sudo[2910]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:30 volumio volumiobt[2912]: INFO [BTSTART] Powering on Bluetooth if needed... Apr 12 21:05:30 volumio volumiobt[2915]: No default controller available Apr 12 21:05:30 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 12 21:05:30 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Apr 12 21:05:31 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 12 21:05:31 volumio volumio[1151]: info: Preload queue cleared Apr 12 21:05:31 volumio volumiobt[2917]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Apr 12 21:05:31 volumio volumiobt[2918]: [83B blob data] Apr 12 21:05:31 volumio volumiobt[2918]: No default controller available Apr 12 21:05:31 volumio volumiobt[2918]: [bluetoothctl]> pairable on Apr 12 21:05:31 volumio volumiobt[2918]: No default controller available Apr 12 21:05:31 volumio volumiobt[2918]: [113B blob data] Apr 12 21:05:31 volumio volumiobt[2918]: [bluetoothctl]> Apr 12 21:05:31 volumio volumiobt[2919]: INFO [BTSTART] Registering Bluetooth agent... Apr 12 21:05:31 volumio volumiobt[2921]: No agent is registered Apr 12 21:05:31 volumio volumiobt[2922]: INFO [BTSTART] Agent registered successfully. Apr 12 21:05:31 volumio volumiobt[2923]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Apr 12 21:05:32 volumio volumiobt[2924]: 2026-04-12 21:05:32 a2dp-agent [INFO] Connecting to system D-Bus Apr 12 21:05:32 volumio volumiobt[2924]: 2026-04-12 21:05:32 a2dp-agent [INFO] Connected to system D-Bus Apr 12 21:05:32 volumio volumiobt[2924]: 2026-04-12 21:05:32 a2dp-agent [ERROR] No Bluetooth adapter found: Bluetooth adapter not found Apr 12 21:05:32 volumio volumiobt[2924]: 2026-04-12 21:05:32 a2dp-agent [ERROR] Agent crashed: Bluetooth adapter not found Apr 12 21:05:32 volumio volumiobt[2924]: Traceback (most recent call last): Apr 12 21:05:32 volumio volumiobt[2924]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:32 volumio volumiobt[2924]: asyncio.run(_run()) Apr 12 21:05:32 volumio volumiobt[2924]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:32 volumio volumiobt[2924]: return runner.run(main) Apr 12 21:05:32 volumio volumiobt[2924]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:32 volumio volumiobt[2924]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:32 volumio volumiobt[2924]: return self._loop.run_until_complete(task) Apr 12 21:05:32 volumio volumiobt[2924]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:32 volumio volumiobt[2924]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:32 volumio volumiobt[2924]: return future.result() Apr 12 21:05:32 volumio volumiobt[2924]: ^^^^^^^^^^^^^^^ Apr 12 21:05:32 volumio volumiobt[2924]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:32 volumio volumiobt[2924]: adapter_path = await find_adapter(bus) Apr 12 21:05:32 volumio volumiobt[2924]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:32 volumio volumiobt[2924]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:32 volumio volumiobt[2924]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:32 volumio volumiobt[2924]: Exception: Bluetooth adapter not found Apr 12 21:05:32 volumio volumiobt[2924]: Traceback (most recent call last): Apr 12 21:05:32 volumio volumiobt[2924]: File "/bin/bt/a2dp-agent", line 234, in Apr 12 21:05:32 volumio volumiobt[2924]: main() Apr 12 21:05:32 volumio volumiobt[2924]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:32 volumio volumiobt[2924]: asyncio.run(_run()) Apr 12 21:05:32 volumio volumiobt[2924]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:32 volumio volumiobt[2924]: return runner.run(main) Apr 12 21:05:32 volumio volumiobt[2924]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:32 volumio volumiobt[2924]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:32 volumio volumiobt[2924]: return self._loop.run_until_complete(task) Apr 12 21:05:32 volumio volumiobt[2924]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:32 volumio volumiobt[2924]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:32 volumio volumiobt[2924]: return future.result() Apr 12 21:05:32 volumio volumiobt[2924]: ^^^^^^^^^^^^^^^ Apr 12 21:05:32 volumio volumiobt[2924]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:32 volumio volumiobt[2924]: adapter_path = await find_adapter(bus) Apr 12 21:05:32 volumio volumiobt[2924]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:32 volumio volumiobt[2924]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:32 volumio volumiobt[2924]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:32 volumio volumiobt[2924]: Exception: Bluetooth adapter not found Apr 12 21:05:32 volumio systemd[1]: volumiobt.service: Main process exited, code=exited, status=1/FAILURE Apr 12 21:05:32 volumio systemd[1]: volumiobt.service: Failed with result 'exit-code'. Apr 12 21:05:32 volumio systemd[1]: volumiobt.service: Consumed 1.661s CPU time. Apr 12 21:05:32 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Apr 12 21:05:32 volumio volumio[1151]: info: Preload queue cleared Apr 12 21:05:32 volumio systemd[1]: volumiobt.service: Scheduled restart job, restart counter is at 10. Apr 12 21:05:32 volumio systemd[1]: Stopped volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:32 volumio systemd[1]: volumiobt.service: Consumed 1.661s CPU time. Apr 12 21:05:33 volumio systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:33 volumio volumiobt[2928]: INFO [BTSTART] Ensuring Bluetooth directory exists... Apr 12 21:05:33 volumio sudo[2929]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Apr 12 21:05:33 volumio sudo[2929]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:33 volumio sudo[2929]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:33 volumio sudo[2931]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Apr 12 21:05:33 volumio sudo[2931]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:33 volumio sudo[2931]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:33 volumio volumiobt[2933]: INFO [BTSTART] Powering on Bluetooth if needed... Apr 12 21:05:33 volumio volumiobt[2936]: No default controller available Apr 12 21:05:34 volumio volumiobt[2938]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Apr 12 21:05:34 volumio volumiobt[2939]: [83B blob data] Apr 12 21:05:34 volumio volumiobt[2939]: No default controller available Apr 12 21:05:34 volumio volumiobt[2939]: [bluetoothctl]> pairable on Apr 12 21:05:34 volumio volumiobt[2939]: No default controller available Apr 12 21:05:34 volumio volumiobt[2939]: [113B blob data] Apr 12 21:05:34 volumio volumiobt[2939]: [bluetoothctl]> Apr 12 21:05:34 volumio volumiobt[2940]: INFO [BTSTART] Registering Bluetooth agent... Apr 12 21:05:34 volumio volumiobt[2942]: No agent is registered Apr 12 21:05:34 volumio volumiobt[2943]: INFO [BTSTART] Agent registered successfully. Apr 12 21:05:34 volumio volumiobt[2944]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Apr 12 21:05:34 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 12 21:05:35 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 12 21:05:35 volumio volumio[1151]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Apr 12 21:05:35 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Apr 12 21:05:35 volumio volumio[1151]: info: Received Get System Version Apr 12 21:05:35 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 12 21:05:35 volumio volumio[1151]: info: Received Get System Info Apr 12 21:05:35 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 21:05:35 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 21:05:35 volumio volumio[1151]: info: Discovery: Getting this device information Apr 12 21:05:35 volumio volumio[1151]: info: CoreCommandRouter::volumioGetState Apr 12 21:05:35 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:05:35 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 21:05:35 volumio volumiobt[2945]: 2026-04-12 21:05:35 a2dp-agent [INFO] Connecting to system D-Bus Apr 12 21:05:35 volumio volumiobt[2945]: 2026-04-12 21:05:35 a2dp-agent [INFO] Connected to system D-Bus Apr 12 21:05:35 volumio volumiobt[2945]: 2026-04-12 21:05:35 a2dp-agent [ERROR] No Bluetooth adapter found: Bluetooth adapter not found Apr 12 21:05:35 volumio volumiobt[2945]: 2026-04-12 21:05:35 a2dp-agent [ERROR] Agent crashed: Bluetooth adapter not found Apr 12 21:05:35 volumio volumiobt[2945]: Traceback (most recent call last): Apr 12 21:05:35 volumio volumiobt[2945]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:35 volumio volumiobt[2945]: asyncio.run(_run()) Apr 12 21:05:35 volumio volumiobt[2945]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:35 volumio volumiobt[2945]: return runner.run(main) Apr 12 21:05:35 volumio volumiobt[2945]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:35 volumio volumiobt[2945]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:35 volumio volumiobt[2945]: return self._loop.run_until_complete(task) Apr 12 21:05:35 volumio volumiobt[2945]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:35 volumio volumiobt[2945]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:35 volumio volumiobt[2945]: return future.result() Apr 12 21:05:35 volumio volumiobt[2945]: ^^^^^^^^^^^^^^^ Apr 12 21:05:35 volumio volumiobt[2945]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:35 volumio volumiobt[2945]: adapter_path = await find_adapter(bus) Apr 12 21:05:35 volumio volumiobt[2945]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:35 volumio volumiobt[2945]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:35 volumio volumiobt[2945]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:35 volumio volumiobt[2945]: Exception: Bluetooth adapter not found Apr 12 21:05:35 volumio volumiobt[2945]: Traceback (most recent call last): Apr 12 21:05:35 volumio volumiobt[2945]: File "/bin/bt/a2dp-agent", line 234, in Apr 12 21:05:35 volumio volumiobt[2945]: main() Apr 12 21:05:35 volumio volumiobt[2945]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:35 volumio volumiobt[2945]: asyncio.run(_run()) Apr 12 21:05:35 volumio volumiobt[2945]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:35 volumio volumiobt[2945]: return runner.run(main) Apr 12 21:05:35 volumio volumiobt[2945]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:35 volumio volumiobt[2945]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:35 volumio volumiobt[2945]: return self._loop.run_until_complete(task) Apr 12 21:05:35 volumio volumiobt[2945]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:35 volumio volumiobt[2945]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:35 volumio volumiobt[2945]: return future.result() Apr 12 21:05:35 volumio volumiobt[2945]: ^^^^^^^^^^^^^^^ Apr 12 21:05:35 volumio volumiobt[2945]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:35 volumio volumiobt[2945]: adapter_path = await find_adapter(bus) Apr 12 21:05:35 volumio volumiobt[2945]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:35 volumio volumiobt[2945]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:35 volumio volumiobt[2945]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:35 volumio volumiobt[2945]: Exception: Bluetooth adapter not found Apr 12 21:05:35 volumio systemd[1]: volumiobt.service: Main process exited, code=exited, status=1/FAILURE Apr 12 21:05:35 volumio systemd[1]: volumiobt.service: Failed with result 'exit-code'. Apr 12 21:05:35 volumio systemd[1]: volumiobt.service: Consumed 1.658s CPU time. Apr 12 21:05:35 volumio systemd[1]: volumiobt.service: Scheduled restart job, restart counter is at 11. Apr 12 21:05:35 volumio systemd[1]: Stopped volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:35 volumio systemd[1]: volumiobt.service: Consumed 1.658s CPU time. Apr 12 21:05:36 volumio systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:36 volumio volumiobt[2947]: INFO [BTSTART] Ensuring Bluetooth directory exists... Apr 12 21:05:36 volumio sudo[2948]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Apr 12 21:05:36 volumio sudo[2948]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:36 volumio sudo[2948]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:36 volumio sudo[2950]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Apr 12 21:05:36 volumio sudo[2950]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:36 volumio sudo[2950]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:36 volumio volumiobt[2952]: INFO [BTSTART] Powering on Bluetooth if needed... Apr 12 21:05:36 volumio volumiobt[2955]: No default controller available Apr 12 21:05:36 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Apr 12 21:05:36 volumio volumio[1151]: info: Preload queue cleared Apr 12 21:05:37 volumio volumiobt[2957]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Apr 12 21:05:37 volumio volumiobt[2958]: [83B blob data] Apr 12 21:05:37 volumio volumiobt[2958]: No default controller available Apr 12 21:05:37 volumio volumiobt[2958]: [bluetoothctl]> pairable on Apr 12 21:05:37 volumio volumiobt[2958]: No default controller available Apr 12 21:05:37 volumio volumiobt[2958]: [113B blob data] Apr 12 21:05:37 volumio volumiobt[2958]: [bluetoothctl]> Apr 12 21:05:37 volumio volumiobt[2959]: INFO [BTSTART] Registering Bluetooth agent... Apr 12 21:05:37 volumio volumiobt[2961]: No agent is registered Apr 12 21:05:37 volumio volumiobt[2962]: INFO [BTSTART] Agent registered successfully. Apr 12 21:05:37 volumio volumiobt[2963]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Apr 12 21:05:38 volumio volumiobt[2964]: 2026-04-12 21:05:38 a2dp-agent [INFO] Connecting to system D-Bus Apr 12 21:05:38 volumio volumiobt[2964]: 2026-04-12 21:05:38 a2dp-agent [INFO] Connected to system D-Bus Apr 12 21:05:38 volumio volumiobt[2964]: 2026-04-12 21:05:38 a2dp-agent [ERROR] No Bluetooth adapter found: Bluetooth adapter not found Apr 12 21:05:38 volumio volumiobt[2964]: 2026-04-12 21:05:38 a2dp-agent [ERROR] Agent crashed: Bluetooth adapter not found Apr 12 21:05:38 volumio volumiobt[2964]: Traceback (most recent call last): Apr 12 21:05:38 volumio volumiobt[2964]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:38 volumio volumiobt[2964]: asyncio.run(_run()) Apr 12 21:05:38 volumio volumiobt[2964]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:38 volumio volumiobt[2964]: return runner.run(main) Apr 12 21:05:38 volumio volumiobt[2964]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:38 volumio volumiobt[2964]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:38 volumio volumiobt[2964]: return self._loop.run_until_complete(task) Apr 12 21:05:38 volumio volumiobt[2964]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:38 volumio volumiobt[2964]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:38 volumio volumiobt[2964]: return future.result() Apr 12 21:05:38 volumio volumiobt[2964]: ^^^^^^^^^^^^^^^ Apr 12 21:05:38 volumio volumiobt[2964]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:38 volumio volumiobt[2964]: adapter_path = await find_adapter(bus) Apr 12 21:05:38 volumio volumiobt[2964]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:38 volumio volumiobt[2964]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:38 volumio volumiobt[2964]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:38 volumio volumiobt[2964]: Exception: Bluetooth adapter not found Apr 12 21:05:38 volumio volumiobt[2964]: Traceback (most recent call last): Apr 12 21:05:38 volumio volumiobt[2964]: File "/bin/bt/a2dp-agent", line 234, in Apr 12 21:05:38 volumio volumiobt[2964]: main() Apr 12 21:05:38 volumio volumiobt[2964]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:38 volumio volumiobt[2964]: asyncio.run(_run()) Apr 12 21:05:38 volumio volumiobt[2964]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:38 volumio volumiobt[2964]: return runner.run(main) Apr 12 21:05:38 volumio volumiobt[2964]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:38 volumio volumiobt[2964]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:38 volumio volumiobt[2964]: return self._loop.run_until_complete(task) Apr 12 21:05:38 volumio volumiobt[2964]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:38 volumio volumiobt[2964]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:38 volumio volumiobt[2964]: return future.result() Apr 12 21:05:38 volumio volumiobt[2964]: ^^^^^^^^^^^^^^^ Apr 12 21:05:38 volumio volumiobt[2964]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:38 volumio volumiobt[2964]: adapter_path = await find_adapter(bus) Apr 12 21:05:38 volumio volumiobt[2964]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:38 volumio volumiobt[2964]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:38 volumio volumiobt[2964]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:38 volumio volumiobt[2964]: Exception: Bluetooth adapter not found Apr 12 21:05:38 volumio systemd[1]: volumiobt.service: Main process exited, code=exited, status=1/FAILURE Apr 12 21:05:38 volumio systemd[1]: volumiobt.service: Failed with result 'exit-code'. Apr 12 21:05:38 volumio systemd[1]: volumiobt.service: Consumed 1.645s CPU time. Apr 12 21:05:38 volumio systemd[1]: volumiobt.service: Scheduled restart job, restart counter is at 12. Apr 12 21:05:38 volumio systemd[1]: Stopped volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:38 volumio systemd[1]: volumiobt.service: Consumed 1.645s CPU time. Apr 12 21:05:39 volumio systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:39 volumio volumiobt[2966]: INFO [BTSTART] Ensuring Bluetooth directory exists... Apr 12 21:05:39 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Apr 12 21:05:39 volumio sudo[2967]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Apr 12 21:05:39 volumio sudo[2967]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:39 volumio sudo[2967]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:39 volumio sudo[2969]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Apr 12 21:05:39 volumio sudo[2969]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:39 volumio sudo[2969]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:39 volumio volumiobt[2971]: INFO [BTSTART] Powering on Bluetooth if needed... Apr 12 21:05:39 volumio volumiobt[2974]: No default controller available Apr 12 21:05:40 volumio volumio[1151]: info: Preload queue cleared Apr 12 21:05:40 volumio volumiobt[2990]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Apr 12 21:05:40 volumio volumiobt[2991]: [83B blob data] Apr 12 21:05:40 volumio volumiobt[2991]: No default controller available Apr 12 21:05:40 volumio volumiobt[2991]: [bluetoothctl]> pairable on Apr 12 21:05:40 volumio volumiobt[2991]: No default controller available Apr 12 21:05:40 volumio volumiobt[2991]: [bluetoothctl]> Apr 12 21:05:40 volumio volumiobt[2992]: INFO [BTSTART] Registering Bluetooth agent... Apr 12 21:05:40 volumio volumiobt[2994]: No agent is registered Apr 12 21:05:40 volumio volumiobt[2995]: INFO [BTSTART] Agent registered successfully. Apr 12 21:05:40 volumio volumiobt[2996]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Apr 12 21:05:41 volumio volumiobt[2997]: 2026-04-12 21:05:41 a2dp-agent [INFO] Connecting to system D-Bus Apr 12 21:05:41 volumio volumiobt[2997]: 2026-04-12 21:05:41 a2dp-agent [INFO] Connected to system D-Bus Apr 12 21:05:41 volumio volumiobt[2997]: 2026-04-12 21:05:41 a2dp-agent [ERROR] No Bluetooth adapter found: Bluetooth adapter not found Apr 12 21:05:41 volumio volumiobt[2997]: 2026-04-12 21:05:41 a2dp-agent [ERROR] Agent crashed: Bluetooth adapter not found Apr 12 21:05:41 volumio volumiobt[2997]: Traceback (most recent call last): Apr 12 21:05:41 volumio volumiobt[2997]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:41 volumio volumiobt[2997]: asyncio.run(_run()) Apr 12 21:05:41 volumio volumiobt[2997]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:41 volumio volumiobt[2997]: return runner.run(main) Apr 12 21:05:41 volumio volumiobt[2997]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:41 volumio volumiobt[2997]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:41 volumio volumiobt[2997]: return self._loop.run_until_complete(task) Apr 12 21:05:41 volumio volumiobt[2997]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:41 volumio volumiobt[2997]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:41 volumio volumiobt[2997]: return future.result() Apr 12 21:05:41 volumio volumiobt[2997]: ^^^^^^^^^^^^^^^ Apr 12 21:05:41 volumio volumiobt[2997]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:41 volumio volumiobt[2997]: adapter_path = await find_adapter(bus) Apr 12 21:05:41 volumio volumiobt[2997]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:41 volumio volumiobt[2997]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:41 volumio volumiobt[2997]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:41 volumio volumiobt[2997]: Exception: Bluetooth adapter not found Apr 12 21:05:41 volumio volumiobt[2997]: Traceback (most recent call last): Apr 12 21:05:41 volumio volumiobt[2997]: File "/bin/bt/a2dp-agent", line 234, in Apr 12 21:05:41 volumio volumiobt[2997]: main() Apr 12 21:05:41 volumio volumiobt[2997]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:41 volumio volumiobt[2997]: asyncio.run(_run()) Apr 12 21:05:41 volumio volumiobt[2997]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:41 volumio volumiobt[2997]: return runner.run(main) Apr 12 21:05:41 volumio volumiobt[2997]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:41 volumio volumiobt[2997]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:41 volumio volumiobt[2997]: return self._loop.run_until_complete(task) Apr 12 21:05:41 volumio volumiobt[2997]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:41 volumio volumiobt[2997]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:41 volumio volumiobt[2997]: return future.result() Apr 12 21:05:41 volumio volumiobt[2997]: ^^^^^^^^^^^^^^^ Apr 12 21:05:41 volumio volumiobt[2997]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:41 volumio volumiobt[2997]: adapter_path = await find_adapter(bus) Apr 12 21:05:41 volumio volumiobt[2997]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:41 volumio volumiobt[2997]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:41 volumio volumiobt[2997]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:41 volumio volumiobt[2997]: Exception: Bluetooth adapter not found Apr 12 21:05:41 volumio systemd[1]: volumiobt.service: Main process exited, code=exited, status=1/FAILURE Apr 12 21:05:41 volumio systemd[1]: volumiobt.service: Failed with result 'exit-code'. Apr 12 21:05:41 volumio systemd[1]: volumiobt.service: Consumed 1.652s CPU time. Apr 12 21:05:41 volumio systemd[1]: volumiobt.service: Scheduled restart job, restart counter is at 13. Apr 12 21:05:41 volumio systemd[1]: Stopped volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:41 volumio systemd[1]: volumiobt.service: Consumed 1.652s CPU time. Apr 12 21:05:42 volumio systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:42 volumio volumiobt[2999]: INFO [BTSTART] Ensuring Bluetooth directory exists... Apr 12 21:05:42 volumio sudo[3000]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Apr 12 21:05:42 volumio sudo[3000]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:42 volumio sudo[3000]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:42 volumio sudo[3002]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Apr 12 21:05:42 volumio sudo[3002]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:42 volumio sudo[3002]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:42 volumio volumiobt[3004]: INFO [BTSTART] Powering on Bluetooth if needed... Apr 12 21:05:42 volumio volumiobt[3007]: No default controller available Apr 12 21:05:43 volumio volumiobt[3009]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Apr 12 21:05:43 volumio volumiobt[3010]: [83B blob data] Apr 12 21:05:43 volumio volumiobt[3010]: No default controller available Apr 12 21:05:43 volumio volumiobt[3010]: [bluetoothctl]> pairable on Apr 12 21:05:43 volumio volumiobt[3010]: No default controller available Apr 12 21:05:43 volumio volumiobt[3010]: [bluetoothctl]> Apr 12 21:05:43 volumio volumiobt[3011]: INFO [BTSTART] Registering Bluetooth agent... Apr 12 21:05:43 volumio volumiobt[3013]: No agent is registered Apr 12 21:05:43 volumio volumiobt[3014]: INFO [BTSTART] Agent registered successfully. Apr 12 21:05:43 volumio volumiobt[3015]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Apr 12 21:05:44 volumio volumio[1151]: info: Preload queue cleared Apr 12 21:05:44 volumio volumio[1151]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 12 21:05:44 volumio volumio[1151]: info: CoreStateMachine::ClearQueue Apr 12 21:05:44 volumio volumio[1151]: info: CoreStateMachine::stop Apr 12 21:05:44 volumio volumio[1151]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 21:05:44 volumio volumio[1151]: info: CorePlayQueue::clearPlayQueue Apr 12 21:05:44 volumio volumio[1151]: info: CorePlayQueue::saveQueue Apr 12 21:05:44 volumio volumio[1151]: info: CoreCommandRouter::volumioPushQueue Apr 12 21:05:44 volumio volumio[1151]: info: CoreStateMachine::addQueueItems Apr 12 21:05:44 volumio volumio[1151]: info: CorePlayQueue::addQueueItems Apr 12 21:05:44 volumio volumio[1151]: info: Preload queue cleared Apr 12 21:05:44 volumio volumio[1151]: info: Adding Item to queue: http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99568320 Apr 12 21:05:44 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Apr 12 21:05:44 volumio volumio[1151]: info: CoreCommandRouter::volumioPushQueue Apr 12 21:05:44 volumio volumio[1151]: info: CorePlayQueue::saveQueue Apr 12 21:05:44 volumio volumio[1151]: info: CoreStateMachine::updateTrackBlock Apr 12 21:05:44 volumio volumio[1151]: info: CorePlayQueue::getTrackBlock Apr 12 21:05:44 volumio volumio[1151]: info: CoreCommandRouter::volumioGetState Apr 12 21:05:44 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:05:44 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Apr 12 21:05:44 volumio volumio[1151]: info: CoreCommandRouter::volumioPlay Apr 12 21:05:44 volumio volumio[1151]: info: CoreStateMachine::play index 0 Apr 12 21:05:44 volumio volumio[1151]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 21:05:44 volumio volumio[1151]: info: CoreStateMachine::stop Apr 12 21:05:44 volumio volumio[1151]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 21:05:44 volumio volumio[1151]: info: CoreStateMachine::play index undefined Apr 12 21:05:44 volumio volumio[1151]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 21:05:44 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:05:44 volumio volumio[1151]: info: CoreStateMachine::startPlaybackTimer Apr 12 21:05:44 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:05:44 volumio volumio[1151]: info: CoreCommandRouter::volumioGetVisibleSources Apr 12 21:05:44 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 21:05:44 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 12 21:05:44 volumio volumio[1151]: info: [1776020744220] ControllerWebradio::clearAddPlayTrack Apr 12 21:05:44 volumio volumio[1151]: verbose: ControllerMpd::sendMpdCommand stop Apr 12 21:05:44 volumio volumio[1151]: info: sendMpdCommand stop took 21 milliseconds Apr 12 21:05:44 volumio volumio[1151]: verbose: ControllerMpd::sendMpdCommand clear Apr 12 21:05:44 volumio volumio[1151]: info: Apr 12 21:05:44 volumio volumio[1151]: ---------------------------- MPD announces system playlist update Apr 12 21:05:44 volumio volumio[1151]: info: Ignoring MPD Status Update Apr 12 21:05:44 volumio volumio[1151]: info: sendMpdCommand clear took 9 milliseconds Apr 12 21:05:44 volumio volumio[1151]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99568320" Apr 12 21:05:44 volumio volumio[1151]: error: updateQueue error: null Apr 12 21:05:44 volumio volumio[1151]: info: ------------------------------ 15ms Apr 12 21:05:44 volumio volumio[1151]: info: Apr 12 21:05:44 volumio volumio[1151]: ---------------------------- MPD announces system playlist update Apr 12 21:05:44 volumio volumio[1151]: info: Ignoring MPD Status Update Apr 12 21:05:44 volumio volumio[1151]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99568320" took 229 milliseconds Apr 12 21:05:44 volumio volumio[1151]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 12 21:05:44 volumio volumio[1151]: verbose: ControllerMpd::sendMpdCommand play Apr 12 21:05:44 volumio volumio[1151]: info: ------------------------------ 15ms Apr 12 21:05:44 volumio volumio[1151]: info: sendMpdCommand play took 12 milliseconds Apr 12 21:05:44 volumio volumiobt[3016]: 2026-04-12 21:05:44 a2dp-agent [INFO] Connecting to system D-Bus Apr 12 21:05:44 volumio volumiobt[3016]: 2026-04-12 21:05:44 a2dp-agent [INFO] Connected to system D-Bus Apr 12 21:05:44 volumio volumiobt[3016]: 2026-04-12 21:05:44 a2dp-agent [ERROR] No Bluetooth adapter found: Bluetooth adapter not found Apr 12 21:05:44 volumio volumiobt[3016]: 2026-04-12 21:05:44 a2dp-agent [ERROR] Agent crashed: Bluetooth adapter not found Apr 12 21:05:44 volumio volumiobt[3016]: Traceback (most recent call last): Apr 12 21:05:44 volumio volumiobt[3016]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:44 volumio volumiobt[3016]: asyncio.run(_run()) Apr 12 21:05:44 volumio volumiobt[3016]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:44 volumio volumiobt[3016]: return runner.run(main) Apr 12 21:05:44 volumio volumiobt[3016]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:44 volumio volumiobt[3016]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:44 volumio volumiobt[3016]: return self._loop.run_until_complete(task) Apr 12 21:05:44 volumio volumiobt[3016]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:44 volumio volumiobt[3016]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:44 volumio volumiobt[3016]: return future.result() Apr 12 21:05:44 volumio volumiobt[3016]: ^^^^^^^^^^^^^^^ Apr 12 21:05:44 volumio volumiobt[3016]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:44 volumio volumiobt[3016]: adapter_path = await find_adapter(bus) Apr 12 21:05:44 volumio volumiobt[3016]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:44 volumio volumiobt[3016]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:44 volumio volumiobt[3016]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:44 volumio volumiobt[3016]: Exception: Bluetooth adapter not found Apr 12 21:05:44 volumio volumiobt[3016]: Traceback (most recent call last): Apr 12 21:05:44 volumio volumiobt[3016]: File "/bin/bt/a2dp-agent", line 234, in Apr 12 21:05:44 volumio volumiobt[3016]: main() Apr 12 21:05:44 volumio volumiobt[3016]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:44 volumio volumiobt[3016]: asyncio.run(_run()) Apr 12 21:05:44 volumio volumiobt[3016]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:44 volumio volumiobt[3016]: return runner.run(main) Apr 12 21:05:44 volumio volumiobt[3016]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:44 volumio volumiobt[3016]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:44 volumio volumiobt[3016]: return self._loop.run_until_complete(task) Apr 12 21:05:44 volumio volumiobt[3016]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:44 volumio volumiobt[3016]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:44 volumio volumiobt[3016]: return future.result() Apr 12 21:05:44 volumio volumiobt[3016]: ^^^^^^^^^^^^^^^ Apr 12 21:05:44 volumio volumiobt[3016]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:44 volumio volumiobt[3016]: adapter_path = await find_adapter(bus) Apr 12 21:05:44 volumio volumiobt[3016]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:44 volumio volumiobt[3016]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:44 volumio volumiobt[3016]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:44 volumio volumiobt[3016]: Exception: Bluetooth adapter not found Apr 12 21:05:44 volumio systemd[1]: volumiobt.service: Main process exited, code=exited, status=1/FAILURE Apr 12 21:05:44 volumio systemd[1]: volumiobt.service: Failed with result 'exit-code'. Apr 12 21:05:44 volumio systemd[1]: volumiobt.service: Consumed 1.733s CPU time. Apr 12 21:05:45 volumio systemd[1]: volumiobt.service: Scheduled restart job, restart counter is at 14. Apr 12 21:05:45 volumio systemd[1]: Stopped volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:45 volumio systemd[1]: volumiobt.service: Consumed 1.733s CPU time. Apr 12 21:05:45 volumio systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:45 volumio volumiobt[3022]: INFO [BTSTART] Ensuring Bluetooth directory exists... Apr 12 21:05:45 volumio sudo[3023]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Apr 12 21:05:45 volumio sudo[3023]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:45 volumio sudo[3023]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:45 volumio sudo[3025]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Apr 12 21:05:45 volumio sudo[3025]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:45 volumio sudo[3025]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:45 volumio volumiobt[3027]: INFO [BTSTART] Powering on Bluetooth if needed... Apr 12 21:05:45 volumio volumiobt[3030]: No default controller available Apr 12 21:05:46 volumio volumio[1151]: info: Apr 12 21:05:46 volumio volumio[1151]: ---------------------------- MPD announces state update: player Apr 12 21:05:46 volumio volumio[1151]: info: ControllerMpd::getState Apr 12 21:05:46 volumio volumio[1151]: verbose: ControllerMpd::sendMpdCommand status Apr 12 21:05:46 volumio volumiobt[3034]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Apr 12 21:05:46 volumio volumio[1151]: info: Apr 12 21:05:46 volumio volumio[1151]: ---------------------------- MPD announces state update: player Apr 12 21:05:46 volumio volumio[1151]: info: sendMpdCommand status took 70 milliseconds Apr 12 21:05:46 volumio volumio[1151]: info: ControllerMpd::getState Apr 12 21:05:46 volumio volumio[1151]: verbose: ControllerMpd::sendMpdCommand status Apr 12 21:05:46 volumio volumio[1151]: verbose: ControllerMpd::parseState Apr 12 21:05:46 volumio volumio[1151]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 21:05:46 volumio volumio[1151]: info: Apr 12 21:05:46 volumio volumio[1151]: ---------------------------- MPD announces system playlist update Apr 12 21:05:46 volumio volumio[1151]: info: Ignoring MPD Status Update Apr 12 21:05:46 volumio volumio[1151]: info: sendMpdCommand status took 15 milliseconds Apr 12 21:05:46 volumio volumio[1151]: info: sendMpdCommand playlistinfo took 9 milliseconds Apr 12 21:05:46 volumio volumio[1151]: verbose: ControllerMpd::parseState Apr 12 21:05:46 volumio volumio[1151]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 12 21:05:46 volumio volumio[1151]: verbose: ControllerMpd::parseTrackInfo Apr 12 21:05:46 volumio volumio[1151]: info: ControllerMpd::pushState Apr 12 21:05:46 volumio volumio[1151]: info: CoreCommandRouter::servicePushState Apr 12 21:05:46 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:05:46 volumio volumio[1151]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Tracklist: https://dancewave.online","artist":"Dance Wave!","album":null,"uri":"https://dancewave.online:443/dance.mp3","trackType":"mp3"} Apr 12 21:05:46 volumio volumio[1151]: verbose: CURRENT POSITION 0 Apr 12 21:05:46 volumio volumio[1151]: info: CoreStateMachine::syncState stateService play Apr 12 21:05:46 volumio volumio[1151]: info: CoreStateMachine::syncState currentStatus stop Apr 12 21:05:46 volumio volumio[1151]: info: ------------------------------ 122ms Apr 12 21:05:46 volumio volumio[1151]: info: ------------------------------ 33ms Apr 12 21:05:46 volumio volumio[1151]: info: sendMpdCommand playlistinfo took 26 milliseconds Apr 12 21:05:46 volumio volumio[1151]: verbose: ControllerMpd::parseTrackInfo Apr 12 21:05:46 volumio volumio[1151]: info: ControllerMpd::pushState Apr 12 21:05:46 volumio volumio[1151]: info: CoreCommandRouter::servicePushState Apr 12 21:05:46 volumio volumio[1151]: info: CorePlayQueue::getTrack 0 Apr 12 21:05:46 volumio volumio[1151]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1225,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Tracklist: https://dancewave.online","artist":"Dance Wave!","album":null,"uri":"https://dancewave.online:443/dance.mp3","trackType":"mp3"} Apr 12 21:05:46 volumio volumio[1151]: verbose: CURRENT POSITION 0 Apr 12 21:05:46 volumio volumio[1151]: info: CoreStateMachine::syncState stateService play Apr 12 21:05:46 volumio volumio[1151]: info: CoreStateMachine::syncState currentStatus play Apr 12 21:05:46 volumio volumio[1151]: info: Received an update from plugin. extracting info from payload Apr 12 21:05:46 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 12 21:05:46 volumio volumio[1151]: info: CoreStateMachine::pushState Apr 12 21:05:46 volumio volumio[1151]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 21:05:46 volumio volumio[1151]: info: CoreCommandRouter::volumioPushState Apr 12 21:05:46 volumio volumiobt[3035]: [83B blob data] Apr 12 21:05:46 volumio volumiobt[3035]: No default controller available Apr 12 21:05:46 volumio volumiobt[3035]: [bluetoothctl]> pairable on Apr 12 21:05:46 volumio volumiobt[3035]: No default controller available Apr 12 21:05:46 volumio volumiobt[3035]: [113B blob data] Apr 12 21:05:46 volumio volumio[1151]: info: MRS: Pushing multiroomSync output update for this device Apr 12 21:05:46 volumio volumio[1151]: info: MRS: Pushing multiroomSync output Apr 12 21:05:46 volumio volumio[1151]: info: CoreCommandRouter::volumioGetState Apr 12 21:05:46 volumio volumio[1151]: info: CoreStateMachine::pushState Apr 12 21:05:46 volumio volumio[1151]: info: CoreCommandRouter::volumioPushState Apr 12 21:05:46 volumio volumio[1151]: info: MRS: Pushing multiroomSync output update for this device Apr 12 21:05:46 volumio volumio[1151]: info: MRS: Pushing multiroomSync output Apr 12 21:05:46 volumio volumio[1151]: info: CoreCommandRouter::volumioGetState Apr 12 21:05:46 volumio volumiobt[3035]: [bluetoothctl]> Apr 12 21:05:46 volumio volumiobt[3037]: INFO [BTSTART] Registering Bluetooth agent... Apr 12 21:05:46 volumio volumio[1151]: info: ------------------------------ 223ms Apr 12 21:05:46 volumio volumiobt[3039]: No agent is registered Apr 12 21:05:47 volumio volumiobt[3040]: INFO [BTSTART] Agent registered successfully. Apr 12 21:05:47 volumio volumiobt[3041]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Apr 12 21:05:47 volumio volumio[1151]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 12 21:05:47 volumio volumio[1151]: TypeError: Cannot read properties of null (reading 'slice') Apr 12 21:05:47 volumio volumio[1151]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41) Apr 12 21:05:47 volumio volumio[1151]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7) Apr 12 21:05:47 volumio volumio[1151]: at Object.onceWrapper (node:events:629:26) Apr 12 21:05:47 volumio volumio[1151]: at ClientRequest.emit (node:events:514:28) Apr 12 21:05:47 volumio volumio[1151]: at HTTPParser.parserOnIncomingClient [as onIncoming] (node:_http_client:693:27) Apr 12 21:05:47 volumio volumio[1151]: at HTTPParser.parserOnHeadersComplete (node:_http_common:119:17) Apr 12 21:05:47 volumio volumio[1151]: at TLSSocket.socketOnData (node:_http_client:535:22) Apr 12 21:05:47 volumio volumio[1151]: at TLSSocket.emit (node:events:514:28) Apr 12 21:05:47 volumio volumio[1151]: at addChunk (node:internal/streams/readable:343:12) Apr 12 21:05:47 volumio volumio[1151]: at readableAddChunk (node:internal/streams/readable:316:9) Apr 12 21:05:47 volumio volumio[1151]: at Readable.push (node:internal/streams/readable:253:10) Apr 12 21:05:47 volumio volumio[1151]: at TLSWrap.onStreamRead (node:internal/stream_base_commons:190:23) Apr 12 21:05:47 volumio volumio[1151]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 12 21:05:48 volumio volumiobt[3042]: 2026-04-12 21:05:48 a2dp-agent [INFO] Connecting to system D-Bus Apr 12 21:05:48 volumio volumiobt[3042]: 2026-04-12 21:05:48 a2dp-agent [INFO] Connected to system D-Bus Apr 12 21:05:48 volumio volumiobt[3042]: 2026-04-12 21:05:48 a2dp-agent [ERROR] No Bluetooth adapter found: Bluetooth adapter not found Apr 12 21:05:48 volumio volumiobt[3042]: 2026-04-12 21:05:48 a2dp-agent [ERROR] Agent crashed: Bluetooth adapter not found Apr 12 21:05:48 volumio volumiobt[3042]: Traceback (most recent call last): Apr 12 21:05:48 volumio volumiobt[3042]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:48 volumio volumiobt[3042]: asyncio.run(_run()) Apr 12 21:05:48 volumio volumiobt[3042]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:48 volumio volumiobt[3042]: return runner.run(main) Apr 12 21:05:48 volumio volumiobt[3042]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:48 volumio volumiobt[3042]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:48 volumio volumiobt[3042]: return self._loop.run_until_complete(task) Apr 12 21:05:48 volumio volumiobt[3042]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:48 volumio volumiobt[3042]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:48 volumio volumiobt[3042]: return future.result() Apr 12 21:05:48 volumio volumiobt[3042]: ^^^^^^^^^^^^^^^ Apr 12 21:05:48 volumio volumiobt[3042]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:48 volumio volumiobt[3042]: adapter_path = await find_adapter(bus) Apr 12 21:05:48 volumio volumiobt[3042]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:48 volumio volumiobt[3042]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:48 volumio volumiobt[3042]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:48 volumio volumiobt[3042]: Exception: Bluetooth adapter not found Apr 12 21:05:48 volumio volumiobt[3042]: Traceback (most recent call last): Apr 12 21:05:48 volumio volumiobt[3042]: File "/bin/bt/a2dp-agent", line 234, in Apr 12 21:05:48 volumio volumiobt[3042]: main() Apr 12 21:05:48 volumio volumiobt[3042]: File "/bin/bt/a2dp-agent", line 225, in main Apr 12 21:05:48 volumio volumiobt[3042]: asyncio.run(_run()) Apr 12 21:05:48 volumio volumiobt[3042]: File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run Apr 12 21:05:48 volumio volumiobt[3042]: return runner.run(main) Apr 12 21:05:48 volumio volumiobt[3042]: ^^^^^^^^^^^^^^^^ Apr 12 21:05:48 volumio volumiobt[3042]: File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run Apr 12 21:05:48 volumio volumiobt[3042]: return self._loop.run_until_complete(task) Apr 12 21:05:48 volumio volumiobt[3042]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:48 volumio volumiobt[3042]: File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete Apr 12 21:05:48 volumio volumiobt[3042]: return future.result() Apr 12 21:05:48 volumio volumiobt[3042]: ^^^^^^^^^^^^^^^ Apr 12 21:05:48 volumio volumiobt[3042]: File "/bin/bt/a2dp-agent", line 175, in _run Apr 12 21:05:48 volumio volumiobt[3042]: adapter_path = await find_adapter(bus) Apr 12 21:05:48 volumio volumiobt[3042]: ^^^^^^^^^^^^^^^^^^^^^^^ Apr 12 21:05:48 volumio volumiobt[3042]: File "/usr/bin/bt/bluezutils.py", line 73, in find_adapter Apr 12 21:05:48 volumio volumiobt[3042]: raise Exception("Bluetooth adapter not found") Apr 12 21:05:48 volumio volumiobt[3042]: Exception: Bluetooth adapter not found Apr 12 21:05:48 volumio systemd[1]: volumiobt.service: Main process exited, code=exited, status=1/FAILURE Apr 12 21:05:48 volumio systemd[1]: volumiobt.service: Failed with result 'exit-code'. Apr 12 21:05:48 volumio systemd[1]: volumiobt.service: Consumed 1.984s CPU time. Apr 12 21:05:48 volumio systemd[1]: volumiobt.service: Scheduled restart job, restart counter is at 15. Apr 12 21:05:48 volumio systemd[1]: Stopped volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:48 volumio systemd[1]: volumiobt.service: Consumed 1.984s CPU time. Apr 12 21:05:48 volumio systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Apr 12 21:05:48 volumio volumiobt[3056]: INFO [BTSTART] Ensuring Bluetooth directory exists... Apr 12 21:05:48 volumio sudo[3057]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Apr 12 21:05:48 volumio sudo[3057]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:48 volumio sudo[3057]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:48 volumio sudo[3059]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Apr 12 21:05:49 volumio sudo[3059]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 21:05:49 volumio sudo[3059]: pam_unix(sudo:session): session closed for user root Apr 12 21:05:49 volumio volumiobt[3061]: INFO [BTSTART] Powering on Bluetooth if needed... Apr 12 21:05:49 volumio volumiobt[3065]: No default controller available Apr 12 21:05:49 volumio sudo[3069]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-12 21:04' Apr 12 21:05:49 volumio sudo[3069]: 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"