Dec 15 15:58:02 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 110. Dec 15 15:58:02 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 15 15:58:02 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 15 15:58:03 volumio upmpdcli[5130]: Could not open config: /tmp/upmpdcli.conf Dec 15 15:58:03 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:58:03 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 15 15:58:07 volumio volumio[1291]: info: CoreCommandRouter::volumioPause Dec 15 15:58:07 volumio volumio[1291]: info: CoreStateMachine::pause Dec 15 15:58:07 volumio volumio[1291]: info: CoreStateMachine::stPlaybackTimer Dec 15 15:58:07 volumio volumio[1291]: info: CoreStateMachine::servicePause Dec 15 15:58:07 volumio volumio[1291]: info: CorePlayQueue::getTrack 12 Dec 15 15:58:07 volumio volumio[1291]: info: CoreCommandRouter::servicePause Dec 15 15:58:07 volumio volumio[1291]: info: ControllerMpd::pause Dec 15 15:58:07 volumio volumio[1291]: verbose: ControllerMpd::sendMpdCommand pause Dec 15 15:58:07 volumio volumio[1291]: info: Dec 15 15:58:07 volumio volumio[1291]: ---------------------------- MPD announces state update: player Dec 15 15:58:07 volumio volumio[1291]: info: sendMpdCommand pause took 1 milliseconds Dec 15 15:58:07 volumio volumio[1291]: info: ControllerMpd::getState Dec 15 15:58:07 volumio volumio[1291]: verbose: ControllerMpd::sendMpdCommand status Dec 15 15:58:07 volumio volumio[1291]: info: sendMpdCommand status took 1 milliseconds Dec 15 15:58:07 volumio volumio[1291]: verbose: ControllerMpd::parseState Dec 15 15:58:07 volumio volumio[1291]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 15 15:58:07 volumio volumio[1291]: info: sendMpdCommand playlistinfo took 0 milliseconds Dec 15 15:58:07 volumio volumio[1291]: verbose: ControllerMpd::parseTrackInfo Dec 15 15:58:07 volumio volumio[1291]: info: ControllerMpd::pushState Dec 15 15:58:07 volumio volumio[1291]: info: CoreCommandRouter::servicePushState Dec 15 15:58:07 volumio volumio[1291]: info: CorePlayQueue::getTrack 12 Dec 15 15:58:07 volumio volumio[1291]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":166941,"duration":762,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"901 Kbps","isStreaming":false,"title":"Taro (includes hidden track 'Hand-Made')","artist":"alt-J (∆)","album":"An Awesome Wave","uri":"USB/689A-2E74/alt-J (∆) - An Awesome Wave/13 - Taro (includes hidden track 'Hand-Made').flac","trackType":"flac"} Dec 15 15:58:07 volumio volumio[1291]: verbose: CURRENT POSITION 12 Dec 15 15:58:07 volumio volumio[1291]: info: CoreStateMachine::syncState stateService pause Dec 15 15:58:07 volumio volumio[1291]: info: CoreStateMachine::syncState currentStatus pause Dec 15 15:58:07 volumio volumio[1291]: info: CoreStateMachine::pushState Dec 15 15:58:07 volumio volumio[1291]: info: CorePlayQueue::getTrack 12 Dec 15 15:58:07 volumio volumio[1291]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 15:58:07 volumio volumio[1291]: info: CoreCommandRouter::volumioPushState Dec 15 15:58:07 volumio volumio[1291]: info: MRS: Pushing multiroomSync output update for this device Dec 15 15:58:07 volumio volumio[1291]: info: MRS: Pushing multiroomSync output Dec 15 15:58:07 volumio volumio[1291]: info: CoreStateMachine::stPlaybackTimer Dec 15 15:58:07 volumio volumio[1291]: info: ------------------------------ 10ms Dec 15 15:58:07 volumio volumio[1291]: info: MRS: Updating multiroomSync output Dec 15 15:58:08 volumio snapserver[4976]: State changed: Radio, state: playing => idle Dec 15 15:58:08 volumio snapserver[4976]: onStateChanged (Radio): idle Dec 15 15:58:13 volumio volumio[1291]: info: CALLMETHOD: audio_interface multiroom saveMultiroomServerOptions [object Object] Dec 15 15:58:13 volumio volumio[1291]: info: CoreCommandRouter::executeOnPlugin: multiroom , saveMultiroomServerOptions Dec 15 15:58:13 volumio volumio[1291]: info: Saving server configuration Dec 15 15:58:13 volumio volumio[1291]: info: Buffer set to: 1500 Dec 15 15:58:13 volumio volumio[1291]: info: StreamBuffer set to: 100 Dec 15 15:58:13 volumio volumio[1291]: info: MRS: Snap server restart Dec 15 15:58:13 volumio volumio[1291]: info: Done Dec 15 15:58:13 volumio sudo[5149]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumioSnapserver Dec 15 15:58:13 volumio sudo[5149]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 15:58:13 volumio snapserver[4976]: Received signal 15: Terminated Dec 15 15:58:13 volumio systemd[1]: Stopping volumioSnapserver.service - Snapcast server... Dec 15 15:58:13 volumio snapserver[4976]: Stopping streamServer Dec 15 15:58:13 volumio snapserver[4976]: done Dec 15 15:58:13 volumio snapserver[4976]: Snapserver terminated. Dec 15 15:58:13 volumio systemd[1]: volumioSnapserver.service: Deactivated successfully. Dec 15 15:58:13 volumio systemd[1]: Stopped volumioSnapserver.service - Snapcast server. Dec 15 15:58:13 volumio systemd[1]: Started volumioSnapserver.service - Snapcast server. Dec 15 15:58:13 volumio sudo[5149]: pam_unix(sudo:session): session closed for user root Dec 15 15:58:13 volumio volumio[1291]: info: MRS: SNAPSERVER STARTED Dec 15 15:58:13 volumio snapserver[5151]: Version 0.26.0 Dec 15 15:58:13 volumio snapserver[5151]: Adding source: pipe:///tmp/multiroom/server/fifo?name=Radio&sampleformat=48000:16:2&codec=flac Dec 15 15:58:13 volumio snapserver[5151]: Settings file: "/var/lib/snapserver/.config/snapserver/server.json" Dec 15 15:58:13 volumio snapserver[5151]: Using HTTP host name: volumio Dec 15 15:58:13 volumio snapserver[5151]: Adding service 'Snapcast' Dec 15 15:58:13 volumio snapserver[5151]: PcmStream: Radio, sampleFormat: 48000:16:2 Dec 15 15:58:13 volumio snapserver[5151]: PipeStream mode: create Dec 15 15:58:13 volumio snapserver[5151]: Stream: {"fragment":"","host":"","path":"/tmp/multiroom/server/fifo","query":{"chunk_ms":"50","codec":"flac","name":"Radio","sampleformat":"48000:16:2"},"raw":"pipe:////tmp/multiroom/server/fifo?chunk_ms=50&codec=flac&name=Radio&sampleformat=48000:16:2","scheme":"pipe"} Dec 15 15:58:13 volumio snapserver[5151]: Init - compression level: 2 Dec 15 15:58:13 volumio snapserver[5151]: Exception: end of file Dec 15 15:58:13 volumio snapserver[5151]: Creating TCP acceptor for address: 0.0.0.0, port: 1705 Dec 15 15:58:13 volumio snapserver[5151]: Creating HTTP acceptor for address: 0.0.0.0, port: 1780 Dec 15 15:58:13 volumio snapserver[5151]: Creating stream acceptor for address: 0.0.0.0, port: 1704 Dec 15 15:58:13 volumio snapserver[5151]: Number of threads: 4, hw threads: 4 Dec 15 15:58:13 volumio ntpd[1147]: PROTO: 185.51.192.62 unlink local addr 192.168.178.12 -> Dec 15 15:58:14 volumio snapserver[5151]: Service 'Snapcast' successfully established. Dec 15 15:58:14 volumio snapserver[5151]: StreamServer::NewConnection: 192.168.178.123 Dec 15 15:58:14 volumio snapserver[5151]: Hello from 00:e0:4c:58:27:84, host: volumioz, v0.26.0, ClientName: Snapclient, OS: Raspbian GNU/Linux 12 (bookworm), Arch: armv7l, Protocol version: 2 Dec 15 15:58:15 volumio ntpd[1147]: PROTO: 213.136.0.252 unlink local addr 192.168.178.12 -> Dec 15 15:58:15 volumio ntpd[1147]: PROTO: 193.123.38.172 unlink local addr 192.168.178.12 -> Dec 15 15:58:18 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 111. Dec 15 15:58:18 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 15 15:58:18 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 15 15:58:18 volumio upmpdcli[5158]: Could not open config: /tmp/upmpdcli.conf Dec 15 15:58:18 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:58:18 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 15 15:58:19 volumio ntpd[1147]: PROTO: 86.80.166.233 unlink local addr 192.168.178.12 -> Dec 15 15:58:20 volumio volumio[1291]: info: CoreCommandRouter::volumioPlay Dec 15 15:58:20 volumio volumio[1291]: info: CoreStateMachine::play index undefined Dec 15 15:58:20 volumio volumio[1291]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 15:58:20 volumio volumio[1291]: info: CorePlayQueue::getTrack 12 Dec 15 15:58:20 volumio volumio[1291]: info: CoreStateMachine::startPlaybackTimer Dec 15 15:58:20 volumio volumio[1291]: info: CorePlayQueue::getTrack 12 Dec 15 15:58:20 volumio volumio[1291]: info: CoreCommandRouter::volumioGetVisibleSources Dec 15 15:58:20 volumio volumio[1291]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 15:58:20 volumio volumio[1291]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 15 15:58:20 volumio volumio[1291]: info: ControllerMpd::resume Dec 15 15:58:20 volumio volumio[1291]: verbose: ControllerMpd::sendMpdCommand play Dec 15 15:58:20 volumio volumio[1291]: info: Dec 15 15:58:20 volumio volumio[1291]: ---------------------------- MPD announces state update: player Dec 15 15:58:20 volumio volumio[1291]: info: sendMpdCommand play took 2 milliseconds Dec 15 15:58:20 volumio volumio[1291]: info: ControllerMpd::getState Dec 15 15:58:20 volumio volumio[1291]: verbose: ControllerMpd::sendMpdCommand status Dec 15 15:58:20 volumio volumio[1291]: info: sendMpdCommand status took 1 milliseconds Dec 15 15:58:20 volumio volumio[1291]: verbose: ControllerMpd::parseState Dec 15 15:58:20 volumio volumio[1291]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 15 15:58:20 volumio volumio[1291]: info: sendMpdCommand playlistinfo took 0 milliseconds Dec 15 15:58:20 volumio volumio[1291]: verbose: ControllerMpd::parseTrackInfo Dec 15 15:58:20 volumio volumio[1291]: info: ControllerMpd::pushState Dec 15 15:58:20 volumio volumio[1291]: info: CoreCommandRouter::servicePushState Dec 15 15:58:20 volumio volumio[1291]: info: CorePlayQueue::getTrack 12 Dec 15 15:58:20 volumio volumio[1291]: verbose: STATE SERVICE {"status":"play","position":0,"seek":167926,"duration":762,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"933 Kbps","isStreaming":false,"title":"Taro (includes hidden track 'Hand-Made')","artist":"alt-J (∆)","album":"An Awesome Wave","uri":"USB/689A-2E74/alt-J (∆) - An Awesome Wave/13 - Taro (includes hidden track 'Hand-Made').flac","trackType":"flac"} Dec 15 15:58:20 volumio volumio[1291]: verbose: CURRENT POSITION 12 Dec 15 15:58:20 volumio volumio[1291]: info: CoreStateMachine::syncState stateService play Dec 15 15:58:20 volumio volumio[1291]: info: CoreStateMachine::syncState currentStatus pause Dec 15 15:58:20 volumio volumio[1291]: info: CoreStateMachine::pushState Dec 15 15:58:20 volumio volumio[1291]: info: CorePlayQueue::getTrack 12 Dec 15 15:58:20 volumio volumio[1291]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 15:58:20 volumio volumio[1291]: info: CoreCommandRouter::volumioPushState Dec 15 15:58:20 volumio volumio[1291]: info: MRS: Pushing multiroomSync output update for this device Dec 15 15:58:20 volumio volumio[1291]: info: MRS: Pushing multiroomSync output Dec 15 15:58:20 volumio volumio[1291]: info: ------------------------------ 11ms Dec 15 15:58:20 volumio volumio[1291]: info: MRS: Updating multiroomSync output Dec 15 15:58:20 volumio snapserver[5151]: State changed: Radio, state: idle => playing Dec 15 15:58:20 volumio snapserver[5151]: onStateChanged (Radio): playing Dec 15 15:58:33 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 112. Dec 15 15:58:33 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 15 15:58:33 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 15 15:58:33 volumio upmpdcli[5191]: Could not open config: /tmp/upmpdcli.conf Dec 15 15:58:33 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:58:33 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 15 15:58:46 volumio volumio[1291]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 15:58:46 volumio volumio[1291]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 15:58:46 volumio volumio[1291]: info: Retrieving Cloud Streaming UI Dec 15 15:58:46 volumio volumio[1291]: info: Getting Tidal Cloud Configuration Dec 15 15:58:46 volumio volumio[1291]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 15:58:46 volumio volumio[1291]: info: Getting Qobuz Cloud Configuration Dec 15 15:58:46 volumio volumio[1291]: info: Asking plugin for UI Config Dec 15 15:58:46 volumio volumio[1291]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 15:58:46 volumio volumio[1291]: info: Getting Spotify Cloud Configuration Dec 15 15:58:46 volumio volumio[1291]: info: Asking plugin for UI Config Dec 15 15:58:46 volumio volumio[1291]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 15:58:46 volumio volumio[1291]: info: Saving Spotify Acccount Dec 15 15:58:46 volumio volumio[1291]: info: Got it Dec 15 15:58:46 volumio volumio[1291]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Dec 15 15:58:46 volumio volumio[1291]: info: Got Tidal Cloud Configuration Dec 15 15:58:46 volumio volumio[1291]: info: Got it Dec 15 15:58:46 volumio volumio[1291]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 15:58:46 volumio volumio[1291]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 15 15:58:46 volumio volumio[1291]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 15 15:58:46 volumio volumio[1291]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 15 15:58:46 volumio volumio[1291]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 15 15:58:46 volumio volumio[1291]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 15:58:46 volumio volumio[1291]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 15:58:46 volumio volumio[1291]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 15:58:46 volumio volumio[1291]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 15:58:46 volumio volumio[1291]: info: CoreCommandRouter::volumioGetBrowseSources Dec 15 15:58:46 volumio volumio[1291]: info: CoreCommandRouter::volumioGetBrowseSources Dec 15 15:58:46 volumio volumio[1291]: info: CoreCommandRouter::volumioGetBrowseSources Dec 15 15:58:47 volumio volumio[1291]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 15:58:47 volumio volumio[1291]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Dec 15 15:58:48 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 113. Dec 15 15:58:48 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 15 15:58:48 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 15 15:58:48 volumio upmpdcli[5212]: Could not open config: /tmp/upmpdcli.conf Dec 15 15:58:48 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:58:48 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 15 15:58:51 volumio volumio[1291]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 15:58:55 volumio volumio[1291]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 15:58:59 volumio volumio[1291]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 15:59:03 volumio volumio[1291]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 15:59:03 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 114. Dec 15 15:59:03 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 15 15:59:03 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 15 15:59:04 volumio upmpdcli[5242]: Could not open config: /tmp/upmpdcli.conf Dec 15 15:59:04 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:59:04 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 15 15:59:06 volumio volumio[1291]: info: CoreCommandRouter::volumioPause Dec 15 15:59:06 volumio volumio[1291]: info: CoreStateMachine::pause Dec 15 15:59:06 volumio volumio[1291]: info: CoreStateMachine::stPlaybackTimer Dec 15 15:59:06 volumio volumio[1291]: info: CoreStateMachine::servicePause Dec 15 15:59:06 volumio volumio[1291]: info: CorePlayQueue::getTrack 12 Dec 15 15:59:06 volumio volumio[1291]: info: CoreCommandRouter::servicePause Dec 15 15:59:06 volumio volumio[1291]: info: ControllerMpd::pause Dec 15 15:59:06 volumio volumio[1291]: verbose: ControllerMpd::sendMpdCommand pause Dec 15 15:59:06 volumio volumio[1291]: info: Dec 15 15:59:06 volumio volumio[1291]: ---------------------------- MPD announces state update: player Dec 15 15:59:06 volumio volumio[1291]: info: sendMpdCommand pause took 1 milliseconds Dec 15 15:59:06 volumio volumio[1291]: info: ControllerMpd::getState Dec 15 15:59:06 volumio volumio[1291]: verbose: ControllerMpd::sendMpdCommand status Dec 15 15:59:06 volumio volumio[1291]: info: sendMpdCommand status took 0 milliseconds Dec 15 15:59:06 volumio volumio[1291]: verbose: ControllerMpd::parseState Dec 15 15:59:06 volumio volumio[1291]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 15 15:59:06 volumio volumio[1291]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 15 15:59:06 volumio volumio[1291]: verbose: ControllerMpd::parseTrackInfo Dec 15 15:59:06 volumio volumio[1291]: info: ControllerMpd::pushState Dec 15 15:59:06 volumio volumio[1291]: info: CoreCommandRouter::servicePushState Dec 15 15:59:06 volumio volumio[1291]: info: CorePlayQueue::getTrack 12 Dec 15 15:59:06 volumio volumio[1291]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":214671,"duration":762,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"914 Kbps","isStreaming":false,"title":"Taro (includes hidden track 'Hand-Made')","artist":"alt-J (∆)","album":"An Awesome Wave","uri":"USB/689A-2E74/alt-J (∆) - An Awesome Wave/13 - Taro (includes hidden track 'Hand-Made').flac","trackType":"flac"} Dec 15 15:59:06 volumio volumio[1291]: verbose: CURRENT POSITION 12 Dec 15 15:59:06 volumio volumio[1291]: info: CoreStateMachine::syncState stateService pause Dec 15 15:59:06 volumio volumio[1291]: info: CoreStateMachine::syncState currentStatus pause Dec 15 15:59:06 volumio volumio[1291]: info: CoreStateMachine::pushState Dec 15 15:59:06 volumio volumio[1291]: info: CorePlayQueue::getTrack 12 Dec 15 15:59:06 volumio volumio[1291]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 15:59:06 volumio volumio[1291]: info: CoreCommandRouter::volumioPushState Dec 15 15:59:06 volumio volumio[1291]: info: MRS: Pushing multiroomSync output update for this device Dec 15 15:59:06 volumio volumio[1291]: info: MRS: Pushing multiroomSync output Dec 15 15:59:06 volumio volumio[1291]: info: CoreStateMachine::stPlaybackTimer Dec 15 15:59:06 volumio volumio[1291]: info: ------------------------------ 10ms Dec 15 15:59:06 volumio volumio[1291]: info: MRS: Updating multiroomSync output Dec 15 15:59:07 volumio volumio[1291]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 15:59:07 volumio snapserver[5151]: State changed: Radio, state: playing => idle Dec 15 15:59:07 volumio snapserver[5151]: onStateChanged (Radio): idle Dec 15 15:59:08 volumio volumio[1291]: info: Enabling MyMusic plugin bluetooth Dec 15 15:59:08 volumio volumio[1291]: info: [MyVolumio PluginManager] Enabling and starting plugin audio_interface bluetooth Dec 15 15:59:08 volumio volumio[1291]: info: Enabling plugin bluetooth Dec 15 15:59:08 volumio volumio[1291]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Dec 15 15:59:08 volumio volumio[1291]: ------------------------------------ BT MESSAGE: [FUNC] onStart Dec 15 15:59:08 volumio volumio[1291]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Dec 15 15:59:08 volumio dbus-daemon[988]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' requested by ':1.12' (uid=1000 pid=1291 comm="/usr/bin/node /volumio/index.js") Dec 15 15:59:08 volumio volumio[1291]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Dec 15 15:59:08 volumio volumio[1291]: ------------------------------------ BT MESSAGE: [metaCache] Created directory: /tmp/bluetooth-cache/ Dec 15 15:59:08 volumio volumio[1291]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Dec 15 15:59:08 volumio systemd[1]: Starting bluetooth.service - Bluetooth service... Dec 15 15:59:09 volumio bluetoothd[5246]: Bluetooth daemon 5.83 Dec 15 15:59:09 volumio dbus-daemon[988]: [system] Successfully activated service 'org.bluez' Dec 15 15:59:09 volumio systemd[1]: Started bluetooth.service - Bluetooth service. Dec 15 15:59:09 volumio bluetoothd[5246]: src/adapter.c:adapter_init() Failed to access management interface Dec 15 15:59:09 volumio bluetoothd[5246]: src/main.c:main() Adapter handling initialization failed Dec 15 15:59:09 volumio systemd[1]: bluetooth.service: Main process exited, code=exited, status=1/FAILURE Dec 15 15:59:09 volumio systemd[1]: bluetooth.service: Failed with result 'exit-code'. Dec 15 15:59:09 volumio volumio[1291]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 15:59:09 volumio volumio[1291]: DBusError: Message recipient disconnected from message bus without replying Dec 15 15:59:09 volumio volumio[1291]: at _methodReturnHandlers. (/myvolumio/plugins/audio_interface/bluetooth/node_modules/dbus-next/lib/bus.js:343:27) Dec 15 15:59:09 volumio volumio[1291]: at handleMessage (/myvolumio/plugins/audio_interface/bluetooth/node_modules/dbus-next/lib/bus.js:101:11) Dec 15 15:59:09 volumio volumio[1291]: at EventEmitter. (/myvolumio/plugins/audio_interface/bluetooth/node_modules/dbus-next/lib/bus.js:151:9) Dec 15 15:59:09 volumio volumio[1291]: at EventEmitter.emit (node:events:514:28) Dec 15 15:59:09 volumio volumio[1291]: at /myvolumio/plugins/audio_interface/bluetooth/node_modules/dbus-next/lib/connection.js:132:14 Dec 15 15:59:09 volumio volumio[1291]: at Socket. (/myvolumio/plugins/audio_interface/bluetooth/node_modules/dbus-next/lib/message.js:65:9) Dec 15 15:59:09 volumio volumio[1291]: at Socket.emit (node:events:514:28) Dec 15 15:59:09 volumio volumio[1291]: at emitReadable_ (node:internal/streams/readable:609:12) Dec 15 15:59:09 volumio volumio[1291]: at process.processTicksAndRejections (node:internal/process/task_queues:81:21) { Dec 15 15:59:09 volumio volumio[1291]: type: 'org.freedesktop.DBus.Error.NoReply', Dec 15 15:59:09 volumio volumio[1291]: text: 'Message recipient disconnected from message bus without replying', Dec 15 15:59:09 volumio volumio[1291]: reply: Message { Dec 15 15:59:09 volumio volumio[1291]: type: 3, Dec 15 15:59:09 volumio volumio[1291]: _sent: false, Dec 15 15:59:09 volumio volumio[1291]: _serial: 3, Dec 15 15:59:09 volumio volumio[1291]: path: undefined, Dec 15 15:59:09 volumio volumio[1291]: interface: undefined, Dec 15 15:59:09 volumio volumio[1291]: member: undefined, Dec 15 15:59:09 volumio volumio[1291]: errorName: 'org.freedesktop.DBus.Error.NoReply', Dec 15 15:59:09 volumio volumio[1291]: replySerial: 2, Dec 15 15:59:09 volumio volumio[1291]: destination: ':1.12', Dec 15 15:59:09 volumio volumio[1291]: sender: 'org.freedesktop.DBus', Dec 15 15:59:09 volumio volumio[1291]: signature: 's', Dec 15 15:59:09 volumio volumio[1291]: body: [ Dec 15 15:59:09 volumio volumio[1291]: 'Message recipient disconnected from message bus without replying' Dec 15 15:59:09 volumio volumio[1291]: ], Dec 15 15:59:09 volumio volumio[1291]: flags: 1 Dec 15 15:59:09 volumio volumio[1291]: } Dec 15 15:59:09 volumio volumio[1291]: } Dec 15 15:59:09 volumio volumio[1291]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 15:59:09 volumio sudo[5266]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 15:58' Dec 15 15:59:09 volumio sudo[5266]: 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"