Feb 22 08:59:00 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 707. Feb 22 08:59:00 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:00 volumio systemd[1]: fusiondsp.service: Consumed 1.337s CPU time. Feb 22 08:59:00 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:01 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 08:59:01 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 08:59:01 volumio volumio[100229]: Traceback (most recent call last): Feb 22 08:59:01 volumio volumio[100229]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 08:59:01 volumio volumio[100229]: from camilladsp import CamillaConnection Feb 22 08:59:01 volumio volumio[100229]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 08:59:01 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 08:59:01 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 08:59:01 volumio systemd[1]: fusiondsp.service: Consumed 1.331s CPU time. Feb 22 08:59:04 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 708. Feb 22 08:59:04 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:04 volumio systemd[1]: fusiondsp.service: Consumed 1.331s CPU time. Feb 22 08:59:04 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:04 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 08:59:04 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 08:59:05 volumio volumio[100233]: Traceback (most recent call last): Feb 22 08:59:05 volumio volumio[100233]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 08:59:05 volumio volumio[100233]: from camilladsp import CamillaConnection Feb 22 08:59:05 volumio volumio[100233]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 08:59:05 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 08:59:05 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 08:59:05 volumio systemd[1]: fusiondsp.service: Consumed 1.337s CPU time. Feb 22 08:59:07 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 709. Feb 22 08:59:07 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:07 volumio systemd[1]: fusiondsp.service: Consumed 1.337s CPU time. Feb 22 08:59:07 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 08:59:07 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 08:59:07 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:08 volumio volumio[100238]: Traceback (most recent call last): Feb 22 08:59:08 volumio volumio[100238]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 08:59:08 volumio volumio[100238]: from camilladsp import CamillaConnection Feb 22 08:59:08 volumio volumio[100238]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 08:59:08 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 08:59:08 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 08:59:08 volumio systemd[1]: fusiondsp.service: Consumed 1.330s CPU time. Feb 22 08:59:10 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 08:59:10 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 08:59:11 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 710. Feb 22 08:59:11 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:11 volumio systemd[1]: fusiondsp.service: Consumed 1.330s CPU time. Feb 22 08:59:11 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:11 volumio volumio[1193]: info: CALLMETHOD: audio_interface fusiondsp resampling [object Object] Feb 22 08:59:11 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: fusiondsp , resampling Feb 22 08:59:11 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 08:59:11 volumio volumio[1193]: error: FusionDsp - Resampling must be disabled in playback settings in order to enable this feature Feb 22 08:59:11 volumio volumio[1193]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 22 08:59:11 volumio volumio[1193]: info: CoreCommandRouter::Close All Modals sent Feb 22 08:59:11 volumio volumio[1193]: info: FusionDsp - no preset used Feb 22 08:59:12 volumio volumio[100257]: Traceback (most recent call last): Feb 22 08:59:12 volumio volumio[100257]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 08:59:12 volumio volumio[100257]: from camilladsp import CamillaConnection Feb 22 08:59:12 volumio volumio[100257]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 08:59:12 volumio volumio[1193]: info: FusionDsp - .Bass-FusionDsp.json,.Classic-FusionDsp.json,.Rock-FusionDsp.json,.Soundtrack-FusionDsp.json,.Voice-FusionDsp.json,.json Feb 22 08:59:12 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 08:59:12 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 08:59:12 volumio systemd[1]: fusiondsp.service: Consumed 1.630s CPU time. Feb 22 08:59:13 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 08:59:13 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 08:59:15 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 711. Feb 22 08:59:15 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:15 volumio systemd[1]: fusiondsp.service: Consumed 1.630s CPU time. Feb 22 08:59:15 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:16 volumio volumio[100263]: Traceback (most recent call last): Feb 22 08:59:16 volumio volumio[100263]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 08:59:16 volumio volumio[100263]: from camilladsp import CamillaConnection Feb 22 08:59:16 volumio volumio[100263]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 08:59:16 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 08:59:16 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 08:59:16 volumio systemd[1]: fusiondsp.service: Consumed 1.330s CPU time. Feb 22 08:59:16 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 08:59:16 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 08:59:18 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 712. Feb 22 08:59:18 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:18 volumio systemd[1]: fusiondsp.service: Consumed 1.330s CPU time. Feb 22 08:59:18 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:19 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 08:59:19 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 08:59:19 volumio volumio[100268]: Traceback (most recent call last): Feb 22 08:59:19 volumio volumio[100268]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 08:59:19 volumio volumio[100268]: from camilladsp import CamillaConnection Feb 22 08:59:19 volumio volumio[100268]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 08:59:20 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 08:59:20 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 08:59:20 volumio systemd[1]: fusiondsp.service: Consumed 1.361s CPU time. Feb 22 08:59:22 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 713. Feb 22 08:59:22 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:22 volumio systemd[1]: fusiondsp.service: Consumed 1.361s CPU time. Feb 22 08:59:22 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:22 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 08:59:22 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 08:59:23 volumio volumio[100286]: Traceback (most recent call last): Feb 22 08:59:23 volumio volumio[100286]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 08:59:23 volumio volumio[100286]: from camilladsp import CamillaConnection Feb 22 08:59:23 volumio volumio[100286]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 08:59:23 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 08:59:23 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 08:59:23 volumio systemd[1]: fusiondsp.service: Consumed 1.344s CPU time. Feb 22 08:59:25 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 714. Feb 22 08:59:25 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:25 volumio systemd[1]: fusiondsp.service: Consumed 1.344s CPU time. Feb 22 08:59:25 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:25 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 08:59:25 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 08:59:26 volumio volumio[100294]: Traceback (most recent call last): Feb 22 08:59:26 volumio volumio[100294]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 08:59:26 volumio volumio[100294]: from camilladsp import CamillaConnection Feb 22 08:59:26 volumio volumio[100294]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 08:59:26 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 08:59:26 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 08:59:26 volumio systemd[1]: fusiondsp.service: Consumed 1.338s CPU time. Feb 22 08:59:28 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 08:59:28 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 08:59:29 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 715. Feb 22 08:59:29 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:29 volumio systemd[1]: fusiondsp.service: Consumed 1.338s CPU time. Feb 22 08:59:29 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:30 volumio volumio[100299]: Traceback (most recent call last): Feb 22 08:59:30 volumio volumio[100299]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 08:59:30 volumio volumio[100299]: from camilladsp import CamillaConnection Feb 22 08:59:30 volumio volumio[100299]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 08:59:30 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 08:59:30 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 08:59:30 volumio systemd[1]: fusiondsp.service: Consumed 1.365s CPU time. Feb 22 08:59:31 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 08:59:31 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 08:59:32 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 716. Feb 22 08:59:32 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:32 volumio systemd[1]: fusiondsp.service: Consumed 1.365s CPU time. Feb 22 08:59:32 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:33 volumio volumio[1193]: info: CALLMETHOD: audio_interface fusiondsp removetools Feb 22 08:59:33 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: fusiondsp , removetools Feb 22 08:59:33 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb Feb 22 08:59:33 volumio volumio[1193]: verbose: ControllerMpd::sendMpdCommand update Feb 22 08:59:33 volumio volumio[1193]: verbose: ControllerMpd::sendMpdCommand status Feb 22 08:59:33 volumio volumio[1193]: info: Feb 22 08:59:33 volumio volumio[1193]: ---------------------------- MPD announces state update: update Feb 22 08:59:33 volumio volumio[1193]: info: sendMpdCommand update took 17 milliseconds Feb 22 08:59:33 volumio volumio[1193]: info: ControllerMpd::getState Feb 22 08:59:33 volumio volumio[1193]: verbose: ControllerMpd::sendMpdCommand status Feb 22 08:59:33 volumio volumio[1193]: verbose: ControllerMpd::sendMpdCommand status Feb 22 08:59:33 volumio volumio[1193]: info: Feb 22 08:59:33 volumio volumio[1193]: ---------------------------- MPD announces state update: update Feb 22 08:59:33 volumio volumio[1193]: info: ControllerMpd::getState Feb 22 08:59:33 volumio volumio[1193]: verbose: ControllerMpd::sendMpdCommand status Feb 22 08:59:33 volumio volumio[1193]: verbose: ControllerMpd::sendMpdCommand status Feb 22 08:59:33 volumio volumio[1193]: info: Feb 22 08:59:33 volumio volumio[1193]: ---------------------------- MPD announces state update: update Feb 22 08:59:33 volumio volumio[1193]: info: ControllerMpd::getState Feb 22 08:59:33 volumio volumio[1193]: verbose: ControllerMpd::sendMpdCommand status Feb 22 08:59:33 volumio volumio[1193]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 22 08:59:33 volumio volumio[1193]: info: CoreCommandRouter::Close All Modals sent Feb 22 08:59:33 volumio volumio[1193]: info: sendMpdCommand status took 116 milliseconds Feb 22 08:59:33 volumio volumio[1193]: info: sendMpdCommand status took 96 milliseconds Feb 22 08:59:33 volumio volumio[1193]: info: sendMpdCommand status took 94 milliseconds Feb 22 08:59:33 volumio volumio[1193]: info: sendMpdCommand status took 94 milliseconds Feb 22 08:59:33 volumio volumio[1193]: info: sendMpdCommand status took 92 milliseconds Feb 22 08:59:33 volumio volumio[1193]: info: sendMpdCommand status took 86 milliseconds Feb 22 08:59:33 volumio volumio[1193]: verbose: ControllerMpd::parseState Feb 22 08:59:33 volumio volumio[1193]: info: Command Router : Notfying DB Updatetrue Feb 22 08:59:33 volumio volumio[1193]: verbose: ControllerMpd::parseState Feb 22 08:59:33 volumio volumio[1193]: verbose: ControllerMpd::parseState Feb 22 08:59:33 volumio volumio[1193]: info: Command Router : Notfying DB Updatetrue Feb 22 08:59:33 volumio volumio[1193]: info: CoreCommandRouter::Close All Modals sent Feb 22 08:59:33 volumio volumio[1193]: verbose: ControllerMpd::parseState Feb 22 08:59:33 volumio volumio[1193]: verbose: ControllerMpd::parseState Feb 22 08:59:33 volumio volumio[1193]: info: Command Router : Notfying DB Updatetrue Feb 22 08:59:33 volumio volumio[1193]: info: CoreCommandRouter::Close All Modals sent Feb 22 08:59:33 volumio volumio[1193]: verbose: ControllerMpd::parseState Feb 22 08:59:34 volumio volumio[100318]: Traceback (most recent call last): Feb 22 08:59:34 volumio volumio[100318]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 08:59:34 volumio volumio[100318]: from camilladsp import CamillaConnection Feb 22 08:59:34 volumio volumio[100318]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 08:59:34 volumio volumio[1193]: info: ControllerMpd::pushState Feb 22 08:59:34 volumio volumio[1193]: info: CoreCommandRouter::servicePushState Feb 22 08:59:34 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 08:59:34 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 08:59:34 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 08:59:34 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 08:59:34 volumio volumio[1193]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Feb 22 08:59:34 volumio volumio[1193]: info: ControllerMpd::pushState Feb 22 08:59:34 volumio volumio[1193]: info: CoreCommandRouter::servicePushState Feb 22 08:59:34 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 08:59:34 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 08:59:34 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 08:59:34 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 08:59:34 volumio volumio[1193]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Feb 22 08:59:34 volumio volumio[1193]: info: ControllerMpd::pushState Feb 22 08:59:34 volumio volumio[1193]: info: CoreCommandRouter::servicePushState Feb 22 08:59:34 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 08:59:34 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 08:59:34 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 08:59:34 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 08:59:34 volumio volumio[1193]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Feb 22 08:59:34 volumio volumio5-onboarding[1520]: time=2026-02-22T08:59:34.234+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=497 volume=100 Feb 22 08:59:34 volumio volumio5-onboarding[1520]: time=2026-02-22T08:59:34.235+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id=http://mscp3.live-streams.nl:8360/flac.flac title="Naim Radio (FLAC)" Feb 22 08:59:34 volumio volumio5-onboarding[1520]: time=2026-02-22T08:59:34.248+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=497 volume=100 Feb 22 08:59:34 volumio volumio5-onboarding[1520]: time=2026-02-22T08:59:34.249+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id=http://mscp3.live-streams.nl:8360/flac.flac title="Naim Radio (FLAC)" Feb 22 08:59:34 volumio volumio5-onboarding[1520]: time=2026-02-22T08:59:34.258+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=497 volume=100 Feb 22 08:59:34 volumio volumio5-onboarding[1520]: time=2026-02-22T08:59:34.259+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id=http://mscp3.live-streams.nl:8360/flac.flac title="Naim Radio (FLAC)" Feb 22 08:59:34 volumio volumio[1193]: info: ------------------------------ 719ms Feb 22 08:59:34 volumio volumio[1193]: info: ------------------------------ 697ms Feb 22 08:59:34 volumio volumio[1193]: info: ------------------------------ 690ms Feb 22 08:59:34 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 08:59:34 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 08:59:34 volumio systemd[1]: fusiondsp.service: Consumed 1.557s CPU time. Feb 22 08:59:34 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 08:59:34 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: undefined, 0 Feb 22 08:59:34 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: webradio | duration: undefined | title: Naim Radio (FLAC) | previous title: Naim Radio (FLAC) Feb 22 08:59:34 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 08:59:34 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 08:59:34 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: undefined, 0 Feb 22 08:59:34 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: webradio | duration: undefined | title: Naim Radio (FLAC) | previous title: Naim Radio (FLAC) Feb 22 08:59:34 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 08:59:34 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 08:59:34 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: undefined, 0 Feb 22 08:59:34 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: webradio | duration: undefined | title: Naim Radio (FLAC) | previous title: Naim Radio (FLAC) Feb 22 08:59:34 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 08:59:34 volumio volumio[1193]: info: FusionDsp - no preset used Feb 22 08:59:34 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 08:59:35 volumio volumio[1193]: info: FusionDsp - .Bass-FusionDsp.json,.Classic-FusionDsp.json,.Rock-FusionDsp.json,.Soundtrack-FusionDsp.json,.Voice-FusionDsp.json,.json Feb 22 08:59:35 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 08:59:36 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 717. Feb 22 08:59:36 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:36 volumio systemd[1]: fusiondsp.service: Consumed 1.557s CPU time. Feb 22 08:59:36 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:38 volumio volumio[100338]: Traceback (most recent call last): Feb 22 08:59:38 volumio volumio[100338]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 08:59:38 volumio volumio[100338]: from camilladsp import CamillaConnection Feb 22 08:59:38 volumio volumio[100338]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 08:59:38 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 08:59:38 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 08:59:38 volumio systemd[1]: fusiondsp.service: Consumed 1.621s CPU time. Feb 22 08:59:38 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 08:59:38 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 08:59:40 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 718. Feb 22 08:59:40 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:40 volumio systemd[1]: fusiondsp.service: Consumed 1.621s CPU time. Feb 22 08:59:40 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:41 volumio volumio[100358]: Traceback (most recent call last): Feb 22 08:59:41 volumio volumio[100358]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 08:59:41 volumio volumio[100358]: from camilladsp import CamillaConnection Feb 22 08:59:41 volumio volumio[100358]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 08:59:41 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 08:59:41 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 08:59:41 volumio systemd[1]: fusiondsp.service: Consumed 1.356s CPU time. Feb 22 08:59:41 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 08:59:41 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 08:59:42 volumio volumio[1193]: info: CALLMETHOD: audio_interface fusiondsp playToolsFile [object Object] Feb 22 08:59:42 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: fusiondsp , playToolsFile Feb 22 08:59:42 volumio volumio[1193]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 22 08:59:42 volumio volumio[1193]: info: CoreStateMachine::ClearQueue Feb 22 08:59:42 volumio volumio[1193]: info: CoreStateMachine::stop Feb 22 08:59:42 volumio volumio[1193]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 22 08:59:42 volumio volumio[1193]: info: CorePlayQueue::clearPlayQueue Feb 22 08:59:42 volumio volumio[1193]: info: CorePlayQueue::saveQueue Feb 22 08:59:42 volumio volumio[1193]: info: CoreCommandRouter::volumioPushQueue Feb 22 08:59:42 volumio volumio[1193]: info: CoreStateMachine::addQueueItems Feb 22 08:59:42 volumio volumio[1193]: info: CorePlayQueue::addQueueItems Feb 22 08:59:42 volumio volumio[1193]: info: Preload queue cleared Feb 22 08:59:42 volumio volumio[1193]: info: Adding Item to queue: INTERNAL/FusionDsp/tools/No file found Feb 22 08:59:42 volumio volumio[1193]: info: Exploding uri INTERNAL/FusionDsp/tools/No file found in service mpd Feb 22 08:59:42 volumio volumio[1193]: error: scanFolder - failure to stat '/mnt/INTERNAL/FusionDsp/tools/No file found' Feb 22 08:59:42 volumio volumio[1193]: info: CoreCommandRouter::volumioClearQueue Feb 22 08:59:42 volumio volumio[1193]: info: CoreStateMachine::ClearQueue Feb 22 08:59:42 volumio volumio[1193]: info: CoreStateMachine::stop Feb 22 08:59:42 volumio volumio[1193]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 22 08:59:42 volumio volumio[1193]: info: CorePlayQueue::clearPlayQueue Feb 22 08:59:42 volumio volumio[1193]: info: CorePlayQueue::saveQueue Feb 22 08:59:42 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 08:59:42 volumio volumio[1193]: info: CoreCommandRouter::volumioPushQueue Feb 22 08:59:42 volumio volumio5-onboarding[1520]: time=2026-02-22T08:59:42.890+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 08:59:42 volumio volumio5-onboarding[1520]: time=2026-02-22T08:59:42.891+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id= title= Feb 22 08:59:42 volumio volumio[1193]: info: CoreCommandRouter::volumioPushQueue Feb 22 08:59:42 volumio volumio[1193]: info: CorePlayQueue::saveQueue Feb 22 08:59:42 volumio volumio[1193]: info: CoreStateMachine::updateTrackBlock Feb 22 08:59:42 volumio volumio[1193]: info: CorePlayQueue::getTrackBlock Feb 22 08:59:42 volumio volumio[1193]: info: CoreCommandRouter::volumioPlay Feb 22 08:59:42 volumio volumio[1193]: info: CoreStateMachine::play index 0 Feb 22 08:59:42 volumio volumio[1193]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 22 08:59:42 volumio volumio[1193]: info: CoreStateMachine::stop Feb 22 08:59:42 volumio volumio[1193]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 22 08:59:42 volumio volumio[1193]: info: CoreStateMachine::play index undefined Feb 22 08:59:42 volumio volumio[1193]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 22 08:59:42 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 08:59:42 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 08:59:42 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: 0, 0 Feb 22 08:59:42 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: Naim Radio (FLAC) Feb 22 08:59:42 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 08:59:43 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 719. Feb 22 08:59:43 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:43 volumio systemd[1]: fusiondsp.service: Consumed 1.356s CPU time. Feb 22 08:59:43 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:44 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 08:59:44 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 08:59:45 volumio volumio[100363]: Traceback (most recent call last): Feb 22 08:59:45 volumio volumio[100363]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 08:59:45 volumio volumio[100363]: from camilladsp import CamillaConnection Feb 22 08:59:45 volumio volumio[100363]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 08:59:45 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 08:59:45 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 08:59:45 volumio systemd[1]: fusiondsp.service: Consumed 1.763s CPU time. Feb 22 08:59:47 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 720. Feb 22 08:59:47 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:47 volumio systemd[1]: fusiondsp.service: Consumed 1.763s CPU time. Feb 22 08:59:47 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:47 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 08:59:47 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 08:59:49 volumio volumio[100369]: Traceback (most recent call last): Feb 22 08:59:49 volumio volumio[100369]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 08:59:49 volumio volumio[100369]: from camilladsp import CamillaConnection Feb 22 08:59:49 volumio volumio[100369]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 08:59:49 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 08:59:49 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 08:59:49 volumio systemd[1]: fusiondsp.service: Consumed 1.342s CPU time. Feb 22 08:59:50 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 22 08:59:50 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 22 08:59:50 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 08:59:50 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 08:59:51 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 721. Feb 22 08:59:51 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:51 volumio systemd[1]: fusiondsp.service: Consumed 1.342s CPU time. Feb 22 08:59:51 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:52 volumio volumio[100387]: Traceback (most recent call last): Feb 22 08:59:52 volumio volumio[100387]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 08:59:52 volumio volumio[100387]: from camilladsp import CamillaConnection Feb 22 08:59:52 volumio volumio[100387]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 08:59:52 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 08:59:52 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 08:59:52 volumio systemd[1]: fusiondsp.service: Consumed 1.344s CPU time. Feb 22 08:59:53 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 08:59:53 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 08:59:54 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 722. Feb 22 08:59:54 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:54 volumio systemd[1]: fusiondsp.service: Consumed 1.344s CPU time. Feb 22 08:59:54 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:56 volumio volumio[100392]: Traceback (most recent call last): Feb 22 08:59:56 volumio volumio[100392]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 08:59:56 volumio volumio[100392]: from camilladsp import CamillaConnection Feb 22 08:59:56 volumio volumio[100392]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 08:59:56 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 08:59:56 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 08:59:56 volumio systemd[1]: fusiondsp.service: Consumed 1.341s CPU time. Feb 22 08:59:56 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 08:59:56 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 08:59:58 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 723. Feb 22 08:59:58 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:58 volumio systemd[1]: fusiondsp.service: Consumed 1.341s CPU time. Feb 22 08:59:58 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 08:59:59 volumio volumio[100396]: Traceback (most recent call last): Feb 22 08:59:59 volumio volumio[100396]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 08:59:59 volumio volumio[100396]: from camilladsp import CamillaConnection Feb 22 08:59:59 volumio volumio[100396]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 08:59:59 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 08:59:59 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 08:59:59 volumio systemd[1]: fusiondsp.service: Consumed 1.358s CPU time. Feb 22 08:59:59 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 08:59:59 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 09:00:01 volumio volumio[1193]: error: Cannot download Available plugins list: Error: ESOCKETTIMEDOUT Feb 22 09:00:01 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 724. Feb 22 09:00:01 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 09:00:01 volumio systemd[1]: fusiondsp.service: Consumed 1.358s CPU time. Feb 22 09:00:01 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 09:00:02 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 09:00:02 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 09:00:03 volumio volumio[100415]: Traceback (most recent call last): Feb 22 09:00:03 volumio volumio[100415]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 09:00:03 volumio volumio[100415]: from camilladsp import CamillaConnection Feb 22 09:00:03 volumio volumio[100415]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 09:00:03 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 09:00:03 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 09:00:03 volumio systemd[1]: fusiondsp.service: Consumed 1.333s CPU time. Feb 22 09:00:04 volumio volumio[1193]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 22 09:00:05 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 725. Feb 22 09:00:05 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 09:00:05 volumio systemd[1]: fusiondsp.service: Consumed 1.333s CPU time. Feb 22 09:00:05 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 09:00:05 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 09:00:05 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 09:00:06 volumio volumio[100419]: Traceback (most recent call last): Feb 22 09:00:06 volumio volumio[100419]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 09:00:06 volumio volumio[100419]: from camilladsp import CamillaConnection Feb 22 09:00:06 volumio volumio[100419]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 09:00:06 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 09:00:06 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 09:00:06 volumio systemd[1]: fusiondsp.service: Consumed 1.337s CPU time. Feb 22 09:00:08 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 726. Feb 22 09:00:08 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 09:00:08 volumio systemd[1]: fusiondsp.service: Consumed 1.337s CPU time. Feb 22 09:00:08 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 09:00:08 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 09:00:09 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 09:00:10 volumio volumio[100424]: Traceback (most recent call last): Feb 22 09:00:10 volumio volumio[100424]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 09:00:10 volumio volumio[100424]: from camilladsp import CamillaConnection Feb 22 09:00:10 volumio volumio[100424]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 09:00:10 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 09:00:10 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 09:00:10 volumio systemd[1]: fusiondsp.service: Consumed 1.364s CPU time. Feb 22 09:00:12 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 09:00:12 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 09:00:12 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 727. Feb 22 09:00:12 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 09:00:12 volumio systemd[1]: fusiondsp.service: Consumed 1.364s CPU time. Feb 22 09:00:12 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 09:00:13 volumio volumio[100442]: Traceback (most recent call last): Feb 22 09:00:13 volumio volumio[100442]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 09:00:13 volumio volumio[100442]: from camilladsp import CamillaConnection Feb 22 09:00:13 volumio volumio[100442]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 09:00:13 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 09:00:13 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 09:00:13 volumio systemd[1]: fusiondsp.service: Consumed 1.327s CPU time. Feb 22 09:00:15 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 09:00:15 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 09:00:15 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 728. Feb 22 09:00:15 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 09:00:15 volumio systemd[1]: fusiondsp.service: Consumed 1.327s CPU time. Feb 22 09:00:15 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 09:00:17 volumio volumio[100446]: Traceback (most recent call last): Feb 22 09:00:17 volumio volumio[100446]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 09:00:17 volumio volumio[100446]: from camilladsp import CamillaConnection Feb 22 09:00:17 volumio volumio[100446]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 09:00:17 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 09:00:17 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 09:00:17 volumio systemd[1]: fusiondsp.service: Consumed 1.334s CPU time. Feb 22 09:00:17 volumio kernel: usb 3-5: reset high-speed USB device number 4 using ehci-pci Feb 22 09:00:17 volumio kernel: sd 0:0:0:0: [sdb] tag#0 FAILED Result: hostbyte=DID_TIME_OUT driverbyte=DRIVER_OK cmd_age=31s Feb 22 09:00:17 volumio kernel: sd 0:0:0:0: [sdb] tag#0 CDB: Read(10) 28 00 1c aa bd 5e 00 00 a2 00 Feb 22 09:00:17 volumio kernel: I/O error, dev sdb, sector 480951646 op 0x0:(READ) flags 0x80700 phys_seg 162 prio class 3 Feb 22 09:00:17 volumio kernel: usb 3-5: reset high-speed USB device number 4 using ehci-pci Feb 22 09:00:17 volumio kernel: sd 0:0:0:0: [sdb] Unaligned partial completion (resid=122867, sector_sz=512) Feb 22 09:00:17 volumio kernel: sd 0:0:0:0: [sdb] tag#0 CDB: Read(10) 28 00 1c ac 60 00 00 00 f0 00 Feb 22 09:00:17 volumio kernel: sd 0:0:0:0: [sdb] tag#0 FAILED Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK cmd_age=0s Feb 22 09:00:17 volumio kernel: sd 0:0:0:0: [sdb] tag#0 CDB: Read(10) 28 00 1c ac 60 00 00 00 f0 00 Feb 22 09:00:17 volumio kernel: I/O error, dev sdb, sector 481058816 op 0x0:(READ) flags 0x84700 phys_seg 240 prio class 3 Feb 22 09:00:17 volumio kernel: usb 3-5: reset high-speed USB device number 4 using ehci-pci Feb 22 09:00:18 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 09:00:18 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 09:00:18 volumio kernel: usb 3-5: device firmware changed Feb 22 09:00:18 volumio kernel: usb 3-5: USB disconnect, device number 4 Feb 22 09:00:18 volumio kernel: sd 0:0:0:0: [sdb] Unaligned partial completion (resid=8179, sector_sz=512) Feb 22 09:00:18 volumio kernel: sd 0:0:0:0: [sdb] tag#0 CDB: Read(10) 28 00 1c ac 60 f0 00 00 10 00 Feb 22 09:00:18 volumio kernel: sd 0:0:0:0: [sdb] tag#0 FAILED Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK cmd_age=0s Feb 22 09:00:18 volumio kernel: sd 0:0:0:0: [sdb] tag#0 CDB: Read(10) 28 00 1c ac 60 f0 00 00 10 00 Feb 22 09:00:18 volumio kernel: I/O error, dev sdb, sector 481059056 op 0x0:(READ) flags 0x80700 phys_seg 16 prio class 3 Feb 22 09:00:18 volumio kernel: device offline error, dev sdb, sector 481058816 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 3 Feb 22 09:00:18 volumio kernel: device offline error, dev sdb, sector 481068800 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 3 Feb 22 09:00:18 volumio kernel: device offline error, dev sdb, sector 481068801 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 3 Feb 22 09:00:18 volumio kernel: device offline error, dev sdb, sector 481068802 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 3 Feb 22 09:00:18 volumio kernel: device offline error, dev sdb, sector 481068803 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 3 Feb 22 09:00:18 volumio kernel: device offline error, dev sdb, sector 481068804 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 3 Feb 22 09:00:18 volumio kernel: device offline error, dev sdb, sector 481068805 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 3 Feb 22 09:00:18 volumio volumio[1193]: info: MPD Database updated - AlbumList cache refreshed Feb 22 09:00:18 volumio volumio[1193]: info: Feb 22 09:00:18 volumio volumio[1193]: ---------------------------- MPD announces state update: database Feb 22 09:00:18 volumio volumio[1193]: verbose: ControllerMpd::sendMpdCommand status Feb 22 09:00:18 volumio volumio[1193]: info: Feb 22 09:00:18 volumio volumio[1193]: ---------------------------- MPD announces state update: update Feb 22 09:00:18 volumio volumio[1193]: info: ControllerMpd::getState Feb 22 09:00:18 volumio volumio[1193]: verbose: ControllerMpd::sendMpdCommand status Feb 22 09:00:18 volumio volumio[1193]: info: ControllerMpd::getState Feb 22 09:00:18 volumio volumio[1193]: verbose: ControllerMpd::sendMpdCommand status Feb 22 09:00:18 volumio volumio[1193]: info: MPD Database updated - AlbumList cache refreshed Feb 22 09:00:18 volumio volumio[1193]: info: Feb 22 09:00:18 volumio volumio[1193]: ---------------------------- MPD announces state update: database Feb 22 09:00:18 volumio volumio[1193]: verbose: ControllerMpd::sendMpdCommand status Feb 22 09:00:18 volumio volumio[1193]: info: Feb 22 09:00:18 volumio volumio[1193]: ---------------------------- MPD announces state update: update Feb 22 09:00:18 volumio volumio[1193]: info: ControllerMpd::getState Feb 22 09:00:18 volumio volumio[1193]: verbose: ControllerMpd::sendMpdCommand status Feb 22 09:00:18 volumio volumio[1193]: info: ControllerMpd::getState Feb 22 09:00:18 volumio volumio[1193]: verbose: ControllerMpd::sendMpdCommand status Feb 22 09:00:18 volumio volumio[1193]: info: MPD Database updated - AlbumList cache refreshed Feb 22 09:00:18 volumio volumio[1193]: info: Feb 22 09:00:18 volumio volumio[1193]: ---------------------------- MPD announces state update: database Feb 22 09:00:18 volumio volumio[1193]: verbose: ControllerMpd::sendMpdCommand status Feb 22 09:00:18 volumio volumio[1193]: info: Feb 22 09:00:18 volumio volumio[1193]: ---------------------------- MPD announces state update: update Feb 22 09:00:18 volumio volumio[1193]: info: ControllerMpd::getState Feb 22 09:00:18 volumio volumio[1193]: verbose: ControllerMpd::sendMpdCommand status Feb 22 09:00:18 volumio volumio[1193]: info: ControllerMpd::getState Feb 22 09:00:18 volumio volumio[1193]: verbose: ControllerMpd::sendMpdCommand status Feb 22 09:00:18 volumio volumio[1193]: info: Partition removed: {"syspath":"/sys/devices/pci0000:00/0000:00:1d.7/usb3/3-5/3-5:1.0/host0/target0:0:0/0:0:0:0/block/sdb/sdb1","ACTION":"remove","CURRENT_TAGS":":systemd:","DEVLINKS":"/dev/disk/by-partuuid/82dce100-01 /dev/disk/by-label/X3 /dev/disk/by-id/usb-ENE_Flash_UB6250_606569746801-part1 /dev/disk/by-uuid/D29D-BDF5 /dev/disk/by-path/pci-0000:00:1d.7-usb-0:5:1.0-scsi-0:0:0:0-part1","DEVNAME":"/dev/sdb1","DEVPATH":"/devices/pci0000:00/0000:00:1d.7/usb3/3-5/3-5:1.0/host0/target0:0:0/0:0:0:0/block/sdb/sdb1","DEVTYPE":"partition","DISKSEQ":"2","ID_BUS":"usb","ID_FS_LABEL":"X3","ID_FS_LABEL_ENC":"X3","ID_FS_TYPE":"exfat","ID_FS_USAGE":"filesystem","ID_FS_UUID":"D29D-BDF5","ID_FS_UUID_ENC":"D29D-BDF5","ID_FS_VERSION":"1.0","ID_MODEL":"UB6250","ID_MODEL_ENC":"UB6250\\x20\\x20\\x20\\x20\\x20\\x20\\x20","ID_MODEL_ID":"6250","ID_PART_ENTRY_DISK":"8:16","ID_PART_ENTRY_NUMBER":"1","ID_PART_ENTRY_OFFSET":"65536","ID_PART_ENTRY_SCHEME":"dos","ID_PART_ENTRY_SIZE":"499679232","ID_PART_ENTRY_TYPE":"0x7","ID_PART_ENTRY_UUID":"82dce100-01","ID_PART_TABLE_TYPE":"dos","ID_PART_TABLE_UUID":"82dce100","ID_PATH":"pci-0000:00:1d.7-usb-0:5:1.0-scsi-0:0:0:0","ID_PATH_TAG":"pci-0000_00_1d_7-usb-0_5_1_0-scsi-0_0_0_0","ID_REVISION":"0100","ID_SERIAL":"ENE_Flash_UB6250_606569746801","ID_SERIAL_SHORT":"606569746801","ID_TYPE":"generic","ID_USB_DRIVER":"ums_eneub6250","ID_USB_INTERFACES":":ff0650:","ID_USB_INTERFACE_NUM":"00","ID_USB_MODEL":"UB6250","ID_USB_MODEL_ENC":"UB6250\\x20\\x20\\x20\\x20\\x20\\x20\\x20","ID_USB_MODEL_ID":"6250","ID_USB_REVISION":"0100","ID_USB_SERIAL":"ENE_Flash_UB6250_606569746801","ID_USB_SERIAL_SHORT":"606569746801","ID_USB_TYPE":"generic","ID_USB_VENDOR":"ENE_Flash","ID_USB_VENDOR_ENC":"ENE\\x20Flash\\x20\\x20","ID_USB_VENDOR_ID":"0cf2","ID_VENDOR":"ENE_Flash","ID_VENDOR_ENC":"ENE\\x20Flash\\x20\\x20","ID_VENDOR_ID":"0cf2","MAJOR":"8","MINOR":"17","PARTN":"1","SEQNUM":"3229","SUBSYSTEM":"block","TAGS":":systemd:","USEC_INITIALIZED":"8038582"} Feb 22 09:00:18 volumio sudo[100456]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/umount -f /dev/sdb1 Feb 22 09:00:18 volumio sudo[100456]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 22 09:00:18 volumio sudo[100456]: pam_unix(sudo:session): session closed for user root Feb 22 09:00:18 volumio systemd[1]: media-X3.mount: Deactivated successfully. Feb 22 09:00:19 volumio kernel: usb 3-5: new high-speed USB device number 6 using ehci-pci Feb 22 09:00:19 volumio kernel: usb 3-5: New USB device found, idVendor=0cf2, idProduct=6250, bcdDevice= 1.00 Feb 22 09:00:19 volumio kernel: usb 3-5: New USB device strings: Mfr=1, Product=2, SerialNumber=4 Feb 22 09:00:19 volumio kernel: usb 3-5: Product: UB6250 Feb 22 09:00:19 volumio kernel: usb 3-5: Manufacturer: ENE Flash Feb 22 09:00:19 volumio kernel: usb 3-5: SerialNumber: 606569746801 Feb 22 09:00:19 volumio kernel: ums_eneub6250 3-5:1.0: USB Mass Storage device detected Feb 22 09:00:19 volumio kernel: scsi host0: usb-storage 3-5:1.0 Feb 22 09:00:19 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 729. Feb 22 09:00:19 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 09:00:19 volumio systemd[1]: fusiondsp.service: Consumed 1.334s CPU time. Feb 22 09:00:19 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 09:00:20 volumio volumio[1193]: info: sendMpdCommand status took 2025 milliseconds Feb 22 09:00:20 volumio volumio[1193]: info: sendMpdCommand status took 1989 milliseconds Feb 22 09:00:20 volumio volumio[1193]: info: sendMpdCommand status took 1989 milliseconds Feb 22 09:00:20 volumio volumio[1193]: verbose: ControllerMpd::parseState Feb 22 09:00:20 volumio volumio[1193]: info: Command Router : Notfying DB Updatefalse Feb 22 09:00:20 volumio volumio[1193]: info: CoreCommandRouter::Close All Modals sent Feb 22 09:00:20 volumio volumio[1193]: verbose: ControllerMpd::parseState Feb 22 09:00:20 volumio volumio[1193]: verbose: ControllerMpd::parseState Feb 22 09:00:20 volumio kernel: scsi 0:0:0:0: Direct-Access USB2.0 CardReader 0100 PQ: 0 ANSI: 2 Feb 22 09:00:20 volumio kernel: sd 0:0:0:0: Attached scsi generic sg1 type 0 Feb 22 09:00:20 volumio kernel: sd 0:0:0:0: [sdb] 499744768 512-byte logical blocks: (256 GB/238 GiB) Feb 22 09:00:20 volumio kernel: sd 0:0:0:0: [sdb] Write Protect is off Feb 22 09:00:20 volumio kernel: sd 0:0:0:0: [sdb] Mode Sense: 0b 00 00 08 Feb 22 09:00:20 volumio kernel: sd 0:0:0:0: [sdb] No Caching mode page found Feb 22 09:00:20 volumio kernel: sd 0:0:0:0: [sdb] Assuming drive cache: write through Feb 22 09:00:20 volumio kernel: sdb: sdb1 Feb 22 09:00:20 volumio kernel: sd 0:0:0:0: [sdb] Attached SCSI disk Feb 22 09:00:20 volumio volumio[1193]: info: ControllerMpd::pushState Feb 22 09:00:20 volumio volumio[1193]: info: CoreCommandRouter::servicePushState Feb 22 09:00:20 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 09:00:20 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:20 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 09:00:20 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 09:00:20 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:20 volumio volumio[1193]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Feb 22 09:00:20 volumio volumio[1193]: verbose: CURRENT POSITION 0 Feb 22 09:00:20 volumio volumio[1193]: info: CoreStateMachine::syncState stateService stop Feb 22 09:00:20 volumio volumio[1193]: info: CoreStateMachine::syncState currentStatus stop Feb 22 09:00:20 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 09:00:20 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:20 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 09:00:20 volumio volumio[1193]: info: No code Feb 22 09:00:20 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 09:00:20 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:20 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 09:00:20 volumio volumio[1193]: info: ControllerMpd::pushState Feb 22 09:00:20 volumio volumio[1193]: info: CoreCommandRouter::servicePushState Feb 22 09:00:20 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 09:00:20 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:20 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 09:00:20 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:20 volumio volumio[1193]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Feb 22 09:00:20 volumio volumio[1193]: verbose: CURRENT POSITION 0 Feb 22 09:00:20 volumio volumio[1193]: info: CoreStateMachine::syncState stateService stop Feb 22 09:00:20 volumio volumio[1193]: info: CoreStateMachine::syncState currentStatus stop Feb 22 09:00:20 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 09:00:20 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:20 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 09:00:20 volumio volumio[1193]: info: No code Feb 22 09:00:20 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 09:00:20 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:20 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 09:00:20 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:20.780+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 09:00:20 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:20.782+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id= title= Feb 22 09:00:20 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:20.798+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 09:00:20 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:20.798+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id= title= Feb 22 09:00:20 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:20.825+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 09:00:20 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:20.825+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id= title= Feb 22 09:00:20 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:20.846+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 09:00:20 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:20.850+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id= title= Feb 22 09:00:20 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:20.862+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 09:00:20 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:20.863+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id= title= Feb 22 09:00:20 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:20.887+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 09:00:20 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:20.887+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id= title= Feb 22 09:00:21 volumio volumio[1193]: info: ------------------------------ 2737ms Feb 22 09:00:21 volumio volumio[1193]: info: ------------------------------ 2738ms Feb 22 09:00:21 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 09:00:21 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 09:00:21 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: 0, 0 Feb 22 09:00:21 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: Naim Radio (FLAC) Feb 22 09:00:21 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 09:00:21 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 09:00:21 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: 0, 0 Feb 22 09:00:21 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: Naim Radio (FLAC) Feb 22 09:00:21 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 09:00:21 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 09:00:21 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: 0, 0 Feb 22 09:00:21 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: Naim Radio (FLAC) Feb 22 09:00:21 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 09:00:21 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 09:00:21 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: 0, 0 Feb 22 09:00:21 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: Naim Radio (FLAC) Feb 22 09:00:21 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 09:00:21 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 09:00:21 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: 0, 0 Feb 22 09:00:21 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: Naim Radio (FLAC) Feb 22 09:00:21 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 09:00:21 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 09:00:21 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: 0, 0 Feb 22 09:00:21 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: Naim Radio (FLAC) Feb 22 09:00:21 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 09:00:21 volumio volumio[100462]: Traceback (most recent call last): Feb 22 09:00:21 volumio volumio[100462]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 09:00:21 volumio volumio[100462]: from camilladsp import CamillaConnection Feb 22 09:00:21 volumio volumio[100462]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 09:00:21 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 09:00:21 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 09:00:21 volumio systemd[1]: fusiondsp.service: Consumed 1.956s CPU time. Feb 22 09:00:21 volumio volumio[1193]: info: sendMpdCommand status took 3335 milliseconds Feb 22 09:00:21 volumio volumio[1193]: info: sendMpdCommand status took 3333 milliseconds Feb 22 09:00:21 volumio volumio[1193]: info: sendMpdCommand status took 3332 milliseconds Feb 22 09:00:21 volumio volumio[1193]: verbose: ControllerMpd::parseState Feb 22 09:00:21 volumio volumio[1193]: info: Command Router : Notfying DB Updatefalse Feb 22 09:00:21 volumio volumio[1193]: info: CoreCommandRouter::Close All Modals sent Feb 22 09:00:21 volumio volumio[1193]: verbose: ControllerMpd::parseState Feb 22 09:00:21 volumio volumio[1193]: verbose: ControllerMpd::parseState Feb 22 09:00:21 volumio volumio[1193]: info: ControllerMpd::pushState Feb 22 09:00:21 volumio volumio[1193]: info: CoreCommandRouter::servicePushState Feb 22 09:00:21 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 09:00:21 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:21 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 09:00:21 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:21 volumio volumio[1193]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Feb 22 09:00:21 volumio volumio[1193]: verbose: CURRENT POSITION 0 Feb 22 09:00:21 volumio volumio[1193]: info: CoreStateMachine::syncState stateService stop Feb 22 09:00:21 volumio volumio[1193]: info: CoreStateMachine::syncState currentStatus stop Feb 22 09:00:21 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 09:00:21 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:21 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 09:00:21 volumio volumio[1193]: info: No code Feb 22 09:00:21 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 09:00:21 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:21 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 09:00:21 volumio volumio[1193]: info: ControllerMpd::pushState Feb 22 09:00:21 volumio volumio[1193]: info: CoreCommandRouter::servicePushState Feb 22 09:00:21 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 09:00:21 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:21 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 09:00:21 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:21 volumio volumio[1193]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Feb 22 09:00:21 volumio volumio[1193]: verbose: CURRENT POSITION 0 Feb 22 09:00:21 volumio volumio[1193]: info: CoreStateMachine::syncState stateService stop Feb 22 09:00:21 volumio volumio[1193]: info: CoreStateMachine::syncState currentStatus stop Feb 22 09:00:21 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 09:00:21 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:21 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 09:00:21 volumio volumio[1193]: info: No code Feb 22 09:00:21 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 09:00:21 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:21 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 09:00:21 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:21.950+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 09:00:21 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:21.952+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id= title= Feb 22 09:00:21 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:21.955+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 09:00:21 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:21.956+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id= title= Feb 22 09:00:21 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:21.959+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 09:00:21 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:21.960+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id= title= Feb 22 09:00:21 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:21.964+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 09:00:21 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:21.965+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id= title= Feb 22 09:00:21 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:21.970+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 09:00:21 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:21.970+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id= title= Feb 22 09:00:21 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:21.973+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 09:00:21 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:21.974+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id= title= Feb 22 09:00:22 volumio volumio[1193]: info: ------------------------------ 3576ms Feb 22 09:00:22 volumio volumio[1193]: info: ------------------------------ 3576ms Feb 22 09:00:22 volumio volumio[1193]: info: Mounting Device X3 Feb 22 09:00:22 volumio sudo[100497]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sdb1 /mnt/USB/X3 -o noatime Feb 22 09:00:22 volumio sudo[100497]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 22 09:00:22 volumio sudo[100497]: pam_unix(sudo:session): session closed for user root Feb 22 09:00:22 volumio volumio[1193]: info: TEST: Here we shall have deleted mounted folder: /mnt/USB/X3 Feb 22 09:00:22 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 09:00:22 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: 0, 0 Feb 22 09:00:22 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: Naim Radio (FLAC) Feb 22 09:00:22 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 09:00:22 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 09:00:22 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: 0, 0 Feb 22 09:00:22 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: Naim Radio (FLAC) Feb 22 09:00:22 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 09:00:22 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 09:00:22 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: 0, 0 Feb 22 09:00:22 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: Naim Radio (FLAC) Feb 22 09:00:22 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 09:00:22 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 09:00:22 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: 0, 0 Feb 22 09:00:22 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: Naim Radio (FLAC) Feb 22 09:00:22 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 09:00:22 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 09:00:22 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: 0, 0 Feb 22 09:00:22 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: Naim Radio (FLAC) Feb 22 09:00:22 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 09:00:22 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 09:00:22 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: 0, 0 Feb 22 09:00:22 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: Naim Radio (FLAC) Feb 22 09:00:22 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 09:00:22 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 09:00:23 volumio volumio[1193]: info: sendMpdCommand status took 4683 milliseconds Feb 22 09:00:23 volumio volumio[1193]: info: sendMpdCommand status took 4679 milliseconds Feb 22 09:00:23 volumio volumio[1193]: info: sendMpdCommand status took 4676 milliseconds Feb 22 09:00:23 volumio volumio[1193]: verbose: ControllerMpd::parseState Feb 22 09:00:23 volumio volumio[1193]: info: Command Router : Notfying DB Updatefalse Feb 22 09:00:23 volumio volumio[1193]: info: CoreCommandRouter::Close All Modals sent Feb 22 09:00:23 volumio volumio[1193]: verbose: ControllerMpd::parseState Feb 22 09:00:23 volumio volumio[1193]: verbose: ControllerMpd::parseState Feb 22 09:00:23 volumio volumio[1193]: info: ControllerMpd::pushState Feb 22 09:00:23 volumio volumio[1193]: info: CoreCommandRouter::servicePushState Feb 22 09:00:23 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 09:00:23 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:23 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 09:00:23 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:23 volumio volumio[1193]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Feb 22 09:00:23 volumio volumio[1193]: verbose: CURRENT POSITION 0 Feb 22 09:00:23 volumio volumio[1193]: info: CoreStateMachine::syncState stateService stop Feb 22 09:00:23 volumio volumio[1193]: info: CoreStateMachine::syncState currentStatus stop Feb 22 09:00:23 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 09:00:23 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:23 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 09:00:23 volumio volumio[1193]: info: No code Feb 22 09:00:23 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 09:00:23 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:23 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 09:00:23 volumio volumio[1193]: info: ControllerMpd::pushState Feb 22 09:00:23 volumio volumio[1193]: info: CoreCommandRouter::servicePushState Feb 22 09:00:23 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 09:00:23 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:23 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 09:00:23 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:23 volumio volumio[1193]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Feb 22 09:00:23 volumio volumio[1193]: verbose: CURRENT POSITION 0 Feb 22 09:00:23 volumio volumio[1193]: info: CoreStateMachine::syncState stateService stop Feb 22 09:00:23 volumio volumio[1193]: info: CoreStateMachine::syncState currentStatus stop Feb 22 09:00:23 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 09:00:23 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:23 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 09:00:23 volumio volumio[1193]: info: No code Feb 22 09:00:23 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 09:00:23 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:23 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 09:00:23 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:23.325+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 09:00:23 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:23.326+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id= title= Feb 22 09:00:23 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:23.332+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 09:00:23 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:23.332+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id= title= Feb 22 09:00:23 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:23.338+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 09:00:23 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:23.339+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id= title= Feb 22 09:00:23 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:23.344+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 09:00:23 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:23.345+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id= title= Feb 22 09:00:23 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:23.352+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 09:00:23 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:23.352+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id= title= Feb 22 09:00:23 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:23.361+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 09:00:23 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:23.362+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id= title= Feb 22 09:00:23 volumio volumio[1193]: info: ------------------------------ 4953ms Feb 22 09:00:23 volumio volumio[1193]: info: ------------------------------ 4954ms Feb 22 09:00:23 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 09:00:23 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: 0, 0 Feb 22 09:00:23 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: Naim Radio (FLAC) Feb 22 09:00:23 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 09:00:23 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 09:00:23 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: 0, 0 Feb 22 09:00:23 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: Naim Radio (FLAC) Feb 22 09:00:23 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 09:00:23 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 09:00:23 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: 0, 0 Feb 22 09:00:23 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: Naim Radio (FLAC) Feb 22 09:00:23 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 09:00:23 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 09:00:23 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: 0, 0 Feb 22 09:00:23 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: Naim Radio (FLAC) Feb 22 09:00:23 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 09:00:23 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 09:00:23 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: 0, 0 Feb 22 09:00:23 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: Naim Radio (FLAC) Feb 22 09:00:23 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 09:00:23 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 09:00:23 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: 0, 0 Feb 22 09:00:23 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: Naim Radio (FLAC) Feb 22 09:00:23 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 09:00:23 volumio volumio[1193]: info: Scanning removed location : "USB/X3" Feb 22 09:00:23 volumio volumio[1193]: verbose: ControllerMpd::sendMpdCommand status Feb 22 09:00:23 volumio volumio[1193]: info: Feb 22 09:00:23 volumio volumio[1193]: ---------------------------- MPD announces state update: update Feb 22 09:00:23 volumio volumio[1193]: info: ControllerMpd::getState Feb 22 09:00:23 volumio volumio[1193]: verbose: ControllerMpd::sendMpdCommand status Feb 22 09:00:23 volumio volumio[1193]: verbose: ControllerMpd::sendMpdCommand status Feb 22 09:00:23 volumio volumio[1193]: info: Feb 22 09:00:23 volumio volumio[1193]: ---------------------------- MPD announces state update: update Feb 22 09:00:23 volumio volumio[1193]: info: ControllerMpd::getState Feb 22 09:00:23 volumio volumio[1193]: verbose: ControllerMpd::sendMpdCommand status Feb 22 09:00:23 volumio volumio[1193]: verbose: ControllerMpd::sendMpdCommand status Feb 22 09:00:23 volumio volumio[1193]: info: Feb 22 09:00:23 volumio volumio[1193]: ---------------------------- MPD announces state update: update Feb 22 09:00:23 volumio volumio[1193]: info: ControllerMpd::getState Feb 22 09:00:23 volumio volumio[1193]: verbose: ControllerMpd::sendMpdCommand status Feb 22 09:00:23 volumio volumio[1193]: info: sendMpdCommand status took 23 milliseconds Feb 22 09:00:23 volumio volumio[1193]: info: sendMpdCommand status took 21 milliseconds Feb 22 09:00:23 volumio volumio[1193]: info: sendMpdCommand status took 18 milliseconds Feb 22 09:00:23 volumio volumio[1193]: info: sendMpdCommand status took 14 milliseconds Feb 22 09:00:23 volumio volumio[1193]: verbose: ControllerMpd::parseState Feb 22 09:00:23 volumio volumio[1193]: info: Command Router : Notfying DB Updatetrue Feb 22 09:00:23 volumio volumio[1193]: info: CoreCommandRouter::Close All Modals sent Feb 22 09:00:23 volumio volumio[1193]: verbose: ControllerMpd::parseState Feb 22 09:00:23 volumio volumio[1193]: verbose: ControllerMpd::parseState Feb 22 09:00:23 volumio volumio[1193]: info: Command Router : Notfying DB Updatetrue Feb 22 09:00:23 volumio volumio[1193]: info: CoreCommandRouter::Close All Modals sent Feb 22 09:00:23 volumio volumio[1193]: verbose: ControllerMpd::parseState Feb 22 09:00:23 volumio volumio[1193]: info: ControllerMpd::pushState Feb 22 09:00:23 volumio volumio[1193]: info: CoreCommandRouter::servicePushState Feb 22 09:00:23 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 09:00:23 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:23 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 09:00:23 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 730. Feb 22 09:00:23 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:23 volumio volumio[1193]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Feb 22 09:00:23 volumio volumio[1193]: verbose: CURRENT POSITION 0 Feb 22 09:00:23 volumio volumio[1193]: info: CoreStateMachine::syncState stateService stop Feb 22 09:00:23 volumio volumio[1193]: info: CoreStateMachine::syncState currentStatus stop Feb 22 09:00:23 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 09:00:23 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:23 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 09:00:23 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 09:00:23 volumio systemd[1]: fusiondsp.service: Consumed 1.956s CPU time. Feb 22 09:00:23 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 09:00:23 volumio volumio[1193]: info: No code Feb 22 09:00:23 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 09:00:23 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:23 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 09:00:23 volumio volumio[1193]: info: ControllerMpd::pushState Feb 22 09:00:23 volumio volumio[1193]: info: CoreCommandRouter::servicePushState Feb 22 09:00:23 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 09:00:23 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:23 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 09:00:23 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:23 volumio volumio[1193]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Feb 22 09:00:23 volumio volumio[1193]: verbose: CURRENT POSITION 0 Feb 22 09:00:23 volumio volumio[1193]: info: CoreStateMachine::syncState stateService stop Feb 22 09:00:23 volumio volumio[1193]: info: CoreStateMachine::syncState currentStatus stop Feb 22 09:00:23 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 09:00:23 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:23 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 09:00:23 volumio volumio[1193]: info: No code Feb 22 09:00:23 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 09:00:23 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:23 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 09:00:23 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 09:00:23 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:23.972+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 09:00:23 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:23.974+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id= title= Feb 22 09:00:23 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:23.978+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 09:00:23 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:23.986+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id= title= Feb 22 09:00:23 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:23.992+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 09:00:23 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:23.993+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id= title= Feb 22 09:00:24 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:23.997+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 09:00:24 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:24.002+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id= title= Feb 22 09:00:24 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:24.006+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 09:00:24 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:24.007+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id= title= Feb 22 09:00:24 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:24.012+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 09:00:24 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:24.016+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id= title= Feb 22 09:00:24 volumio volumio[1193]: info: ------------------------------ 498ms Feb 22 09:00:24 volumio volumio[1193]: info: ------------------------------ 497ms Feb 22 09:00:24 volumio volumio[1193]: info: sendMpdCommand status took 505 milliseconds Feb 22 09:00:24 volumio volumio[1193]: info: sendMpdCommand status took 502 milliseconds Feb 22 09:00:24 volumio volumio[1193]: verbose: ControllerMpd::parseState Feb 22 09:00:24 volumio volumio[1193]: info: Command Router : Notfying DB Updatetrue Feb 22 09:00:24 volumio volumio[1193]: info: CoreCommandRouter::Close All Modals sent Feb 22 09:00:24 volumio volumio[1193]: verbose: ControllerMpd::parseState Feb 22 09:00:24 volumio volumio[1193]: info: ControllerMpd::pushState Feb 22 09:00:24 volumio volumio[1193]: info: CoreCommandRouter::servicePushState Feb 22 09:00:24 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 09:00:24 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:24 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 09:00:24 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:24 volumio volumio[1193]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Feb 22 09:00:24 volumio volumio[1193]: verbose: CURRENT POSITION 0 Feb 22 09:00:24 volumio volumio[1193]: info: CoreStateMachine::syncState stateService stop Feb 22 09:00:24 volumio volumio[1193]: info: CoreStateMachine::syncState currentStatus stop Feb 22 09:00:24 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 09:00:24 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:24 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 09:00:24 volumio volumio[1193]: info: No code Feb 22 09:00:24 volumio volumio[1193]: info: CoreStateMachine::pushState Feb 22 09:00:24 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:24 volumio volumio[1193]: info: CoreCommandRouter::volumioPushState Feb 22 09:00:24 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:24.461+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 09:00:24 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:24.462+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id= title= Feb 22 09:00:24 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:24.470+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 09:00:24 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:24.475+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id= title= Feb 22 09:00:24 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:24.479+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" state=STATUS_STOPPED positionMs=0 volume=100 Feb 22 09:00:24 volumio volumio5-onboarding[1520]: time=2026-02-22T09:00:24.488+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.73:50212 @ 0xc000313b60" id= title= Feb 22 09:00:24 volumio volumio[1193]: info: ------------------------------ 961ms Feb 22 09:00:24 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 09:00:24 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: 0, 0 Feb 22 09:00:24 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: Naim Radio (FLAC) Feb 22 09:00:24 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 09:00:24 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 09:00:24 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: 0, 0 Feb 22 09:00:24 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: Naim Radio (FLAC) Feb 22 09:00:24 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 09:00:24 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 09:00:24 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: 0, 0 Feb 22 09:00:24 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: Naim Radio (FLAC) Feb 22 09:00:24 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 09:00:24 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 09:00:24 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: 0, 0 Feb 22 09:00:24 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: Naim Radio (FLAC) Feb 22 09:00:24 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 09:00:24 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 09:00:24 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: 0, 0 Feb 22 09:00:24 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: Naim Radio (FLAC) Feb 22 09:00:24 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 09:00:24 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 09:00:24 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: 0, 0 Feb 22 09:00:24 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: Naim Radio (FLAC) Feb 22 09:00:24 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 09:00:24 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 09:00:24 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: 0, 0 Feb 22 09:00:24 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: Naim Radio (FLAC) Feb 22 09:00:24 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 09:00:24 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 09:00:24 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: 0, 0 Feb 22 09:00:24 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: Naim Radio (FLAC) Feb 22 09:00:24 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 09:00:24 volumio volumio[1193]: info: [LastFM] using existing timer Feb 22 09:00:24 volumio volumio[1193]: info: [LastFM] Undefined track duration or too short for scrobbling: 0, 0 Feb 22 09:00:24 volumio volumio[1193]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: Naim Radio (FLAC) Feb 22 09:00:24 volumio volumio[1193]: info: =================> [timer] is active: false | can continue: false | timer started at: 1771738191559 Feb 22 09:00:24 volumio kernel: usb 3-5: reset high-speed USB device number 6 using ehci-pci Feb 22 09:00:25 volumio volumio[100513]: Traceback (most recent call last): Feb 22 09:00:25 volumio volumio[100513]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 09:00:25 volumio volumio[100513]: from camilladsp import CamillaConnection Feb 22 09:00:25 volumio volumio[100513]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 09:00:25 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 09:00:25 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 09:00:25 volumio systemd[1]: fusiondsp.service: Consumed 1.608s CPU time. Feb 22 09:00:25 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 09:00:25 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 09:00:27 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 731. Feb 22 09:00:27 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 09:00:27 volumio systemd[1]: fusiondsp.service: Consumed 1.608s CPU time. Feb 22 09:00:27 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 09:00:28 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 09:00:29 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 09:00:29 volumio volumio[100521]: Traceback (most recent call last): Feb 22 09:00:29 volumio volumio[100521]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 09:00:29 volumio volumio[100521]: from camilladsp import CamillaConnection Feb 22 09:00:29 volumio volumio[100521]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 09:00:29 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 09:00:29 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 09:00:29 volumio systemd[1]: fusiondsp.service: Consumed 1.352s CPU time. Feb 22 09:00:30 volumio kernel: sd 0:0:0:0: [sdb] tag#0 FAILED Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK cmd_age=5s Feb 22 09:00:30 volumio kernel: sd 0:0:0:0: [sdb] tag#0 CDB: Read(10) 28 00 1d 01 53 00 00 00 f0 00 Feb 22 09:00:30 volumio kernel: blk_print_req_error: 1797 callbacks suppressed Feb 22 09:00:30 volumio kernel: I/O error, dev sdb, sector 486626048 op 0x0:(READ) flags 0x84700 phys_seg 30 prio class 2 Feb 22 09:00:30 volumio kernel: usb 3-5: reset high-speed USB device number 6 using ehci-pci Feb 22 09:00:30 volumio kernel: sd 0:0:0:0: [sdb] Unaligned partial completion (resid=8179, sector_sz=512) Feb 22 09:00:30 volumio kernel: sd 0:0:0:0: [sdb] tag#0 CDB: Read(10) 28 00 1d 01 53 f0 00 00 10 00 Feb 22 09:00:30 volumio kernel: sd 0:0:0:0: [sdb] tag#0 FAILED Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK cmd_age=0s Feb 22 09:00:30 volumio kernel: sd 0:0:0:0: [sdb] tag#0 CDB: Read(10) 28 00 1d 01 53 f0 00 00 10 00 Feb 22 09:00:30 volumio kernel: I/O error, dev sdb, sector 486626288 op 0x0:(READ) flags 0x80700 phys_seg 2 prio class 2 Feb 22 09:00:30 volumio kernel: usb 3-5: reset high-speed USB device number 6 using ehci-pci Feb 22 09:00:30 volumio kernel: sd 0:0:0:0: [sdb] Unaligned partial completion (resid=122867, sector_sz=512) Feb 22 09:00:30 volumio kernel: sd 0:0:0:0: [sdb] tag#0 CDB: Read(10) 28 00 1d 01 54 00 00 00 f0 00 Feb 22 09:00:30 volumio kernel: sd 0:0:0:0: [sdb] tag#0 FAILED Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK cmd_age=0s Feb 22 09:00:30 volumio kernel: sd 0:0:0:0: [sdb] tag#0 CDB: Read(10) 28 00 1d 01 54 00 00 00 f0 00 Feb 22 09:00:30 volumio kernel: I/O error, dev sdb, sector 486626304 op 0x0:(READ) flags 0x84700 phys_seg 30 prio class 2 Feb 22 09:00:30 volumio kernel: usb 3-5: reset high-speed USB device number 6 using ehci-pci Feb 22 09:00:31 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 732. Feb 22 09:00:31 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 09:00:31 volumio systemd[1]: fusiondsp.service: Consumed 1.352s CPU time. Feb 22 09:00:31 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 09:00:31 volumio kernel: usb 3-5: device firmware changed Feb 22 09:00:31 volumio kernel: sd 0:0:0:0: [sdb] Unaligned partial completion (resid=8179, sector_sz=512) Feb 22 09:00:31 volumio kernel: sd 0:0:0:0: [sdb] tag#0 CDB: Read(10) 28 00 1d 01 54 f0 00 00 10 00 Feb 22 09:00:31 volumio kernel: sd 0:0:0:0: [sdb] tag#0 FAILED Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK cmd_age=0s Feb 22 09:00:31 volumio kernel: sd 0:0:0:0: [sdb] tag#0 CDB: Read(10) 28 00 1d 01 54 f0 00 00 10 00 Feb 22 09:00:31 volumio kernel: I/O error, dev sdb, sector 486626544 op 0x0:(READ) flags 0x80700 phys_seg 2 prio class 2 Feb 22 09:00:31 volumio kernel: usb 3-5: USB disconnect, device number 6 Feb 22 09:00:31 volumio kernel: device offline error, dev sdb, sector 486626048 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2 Feb 22 09:00:31 volumio kernel: device offline error, dev sdb, sector 488176384 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 2 Feb 22 09:00:31 volumio kernel: device offline error, dev sdb, sector 488176384 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2 Feb 22 09:00:31 volumio volumio[1193]: info: Partition removed: {"syspath":"/sys/devices/pci0000:00/0000:00:1d.7/usb3/3-5/3-5:1.0/host0/target0:0:0/0:0:0:0/block/sdb/sdb1","ACTION":"remove","CURRENT_TAGS":":systemd:","DEVLINKS":"/dev/disk/by-path/pci-0000:00:1d.7-usb-0:5:1.0-scsi-0:0:0:0-part1 /dev/disk/by-label/X3 /dev/disk/by-partuuid/82dce100-01 /dev/disk/by-uuid/D29D-BDF5 /dev/disk/by-id/usb-ENE_Flash_UB6250_606569746801-part1","DEVNAME":"/dev/sdb1","DEVPATH":"/devices/pci0000:00/0000:00:1d.7/usb3/3-5/3-5:1.0/host0/target0:0:0/0:0:0:0/block/sdb/sdb1","DEVTYPE":"partition","DISKSEQ":"12","ID_BUS":"usb","ID_FS_LABEL":"X3","ID_FS_LABEL_ENC":"X3","ID_FS_TYPE":"exfat","ID_FS_USAGE":"filesystem","ID_FS_UUID":"D29D-BDF5","ID_FS_UUID_ENC":"D29D-BDF5","ID_FS_VERSION":"1.0","ID_MODEL":"UB6250","ID_MODEL_ENC":"UB6250\\x20\\x20\\x20\\x20\\x20\\x20\\x20","ID_MODEL_ID":"6250","ID_PART_ENTRY_DISK":"8:16","ID_PART_ENTRY_NUMBER":"1","ID_PART_ENTRY_OFFSET":"65536","ID_PART_ENTRY_SCHEME":"dos","ID_PART_ENTRY_SIZE":"499679232","ID_PART_ENTRY_TYPE":"0x7","ID_PART_ENTRY_UUID":"82dce100-01","ID_PART_TABLE_TYPE":"dos","ID_PART_TABLE_UUID":"82dce100","ID_PATH":"pci-0000:00:1d.7-usb-0:5:1.0-scsi-0:0:0:0","ID_PATH_TAG":"pci-0000_00_1d_7-usb-0_5_1_0-scsi-0_0_0_0","ID_REVISION":"0100","ID_SERIAL":"ENE_Flash_UB6250_606569746801","ID_SERIAL_SHORT":"606569746801","ID_TYPE":"generic","ID_USB_DRIVER":"ums_eneub6250","ID_USB_INTERFACES":":ff0650:","ID_USB_INTERFACE_NUM":"00","ID_USB_MODEL":"UB6250","ID_USB_MODEL_ENC":"UB6250\\x20\\x20\\x20\\x20\\x20\\x20\\x20","ID_USB_MODEL_ID":"6250","ID_USB_REVISION":"0100","ID_USB_SERIAL":"ENE_Flash_UB6250_606569746801","ID_USB_SERIAL_SHORT":"606569746801","ID_USB_TYPE":"generic","ID_USB_VENDOR":"ENE_Flash","ID_USB_VENDOR_ENC":"ENE\\x20Flash\\x20\\x20","ID_USB_VENDOR_ID":"0cf2","ID_VENDOR":"ENE_Flash","ID_VENDOR_ENC":"ENE\\x20Flash\\x20\\x20","ID_VENDOR_ID":"0cf2","MAJOR":"8","MINOR":"17","PARTN":"1","SEQNUM":"3263","SUBSYSTEM":"block","TAGS":":systemd:","USEC_INITIALIZED":"2829191043"} Feb 22 09:00:31 volumio sudo[100548]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/umount -f /dev/sdb1 Feb 22 09:00:31 volumio sudo[100548]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 22 09:00:31 volumio sudo[100548]: pam_unix(sudo:session): session closed for user root Feb 22 09:00:31 volumio kernel: usb 3-5: new high-speed USB device number 7 using ehci-pci Feb 22 09:00:31 volumio volumio[1193]: umount: /media/X3: target is busy. Feb 22 09:00:31 volumio volumio[1193]: error: Failed to umount X3: Error: Command failed: /usr/bin/sudo /bin/umount -f "/dev/sdb1" Feb 22 09:00:31 volumio volumio[1193]: umount: /media/X3: target is busy. Feb 22 09:00:32 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 09:00:32 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 09:00:32 volumio volumio[100540]: Traceback (most recent call last): Feb 22 09:00:32 volumio volumio[100540]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 09:00:32 volumio volumio[100540]: from camilladsp import CamillaConnection Feb 22 09:00:32 volumio volumio[100540]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 09:00:32 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 09:00:32 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 09:00:32 volumio systemd[1]: fusiondsp.service: Consumed 1.404s CPU time. Feb 22 09:00:34 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 733. Feb 22 09:00:34 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 09:00:34 volumio systemd[1]: fusiondsp.service: Consumed 1.404s CPU time. Feb 22 09:00:34 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 09:00:35 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 09:00:35 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 09:00:36 volumio volumio[100554]: Traceback (most recent call last): Feb 22 09:00:36 volumio volumio[100554]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 09:00:36 volumio volumio[100554]: from camilladsp import CamillaConnection Feb 22 09:00:36 volumio volumio[100554]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 09:00:36 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 09:00:36 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 09:00:36 volumio systemd[1]: fusiondsp.service: Consumed 1.357s CPU time. Feb 22 09:00:36 volumio kernel: usb 3-5: New USB device found, idVendor=0cf2, idProduct=6250, bcdDevice= 1.00 Feb 22 09:00:36 volumio kernel: usb 3-5: New USB device strings: Mfr=1, Product=2, SerialNumber=4 Feb 22 09:00:37 volumio kernel: usb 3-5: Product: UB6250 Feb 22 09:00:37 volumio kernel: usb 3-5: Manufacturer: ENE Flash Feb 22 09:00:37 volumio kernel: usb 3-5: SerialNumber: 606569746801 Feb 22 09:00:37 volumio kernel: ums_eneub6250 3-5:1.0: USB Mass Storage device detected Feb 22 09:00:37 volumio kernel: scsi host5: usb-storage 3-5:1.0 Feb 22 09:00:38 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 09:00:38 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 09:00:38 volumio kernel: usb 3-5: reset high-speed USB device number 7 using ehci-pci Feb 22 09:00:38 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 734. Feb 22 09:00:38 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 09:00:38 volumio systemd[1]: fusiondsp.service: Consumed 1.357s CPU time. Feb 22 09:00:38 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 09:00:38 volumio kernel: usb 3-5: reset high-speed USB device number 7 using ehci-pci Feb 22 09:00:38 volumio kernel: usb 3-5: reset high-speed USB device number 7 using ehci-pci Feb 22 09:00:39 volumio kernel: usb 3-5: reset high-speed USB device number 7 using ehci-pci Feb 22 09:00:39 volumio volumio[100565]: Traceback (most recent call last): Feb 22 09:00:39 volumio volumio[100565]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 09:00:39 volumio volumio[100565]: from camilladsp import CamillaConnection Feb 22 09:00:39 volumio volumio[100565]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 09:00:39 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 09:00:39 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 09:00:39 volumio systemd[1]: fusiondsp.service: Consumed 1.341s CPU time. Feb 22 09:00:40 volumio volumio[1193]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Feb 22 09:00:40 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Feb 22 09:00:40 volumio volumio[1193]: info: Creating Spotify config file Feb 22 09:00:40 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 09:00:40 volumio volumio[1193]: info: Spotify config file written Feb 22 09:00:41 volumio sudo[100583]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 22 09:00:41 volumio sudo[100583]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 22 09:00:41 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 09:00:41 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 09:00:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 22 09:00:41 volumio go-librespot[100585]: go-librespot daemon starting... Feb 22 09:00:41 volumio sudo[100583]: pam_unix(sudo:session): session closed for user root Feb 22 09:00:41 volumio go-librespot[100586]: time="2026-02-22T09:00:41+03:00" level=info msg="running go-librespot 0.6.2" Feb 22 09:00:41 volumio go-librespot[100586]: time="2026-02-22T09:00:41+03:00" level=debug msg="app state loaded" Feb 22 09:00:41 volumio go-librespot[100586]: time="2026-02-22T09:00:41+03:00" level=debug msg="stored credentials not found" Feb 22 09:00:41 volumio go-librespot[100586]: time="2026-02-22T09:00:41+03:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 22 09:00:41 volumio go-librespot[100586]: time="2026-02-22T09:00:41+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 22 09:00:41 volumio go-librespot[100586]: time="2026-02-22T09:00:41+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 22 09:00:41 volumio go-librespot[100586]: time="2026-02-22T09:00:41+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 22 09:00:41 volumio go-librespot[100586]: time="2026-02-22T09:00:41+03:00" level=info msg="zeroconf server listening on port 37193" Feb 22 09:00:41 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 735. Feb 22 09:00:41 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 09:00:41 volumio systemd[1]: fusiondsp.service: Consumed 1.341s CPU time. Feb 22 09:00:41 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 09:00:43 volumio volumio[100595]: Traceback (most recent call last): Feb 22 09:00:43 volumio volumio[100595]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 09:00:43 volumio volumio[100595]: from camilladsp import CamillaConnection Feb 22 09:00:43 volumio volumio[100595]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 09:00:43 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 09:00:43 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 09:00:43 volumio systemd[1]: fusiondsp.service: Consumed 1.345s CPU time. Feb 22 09:00:43 volumio volumio[1193]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Feb 22 09:00:43 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Feb 22 09:00:43 volumio volumio[1193]: info: Creating Spotify config file Feb 22 09:00:43 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 09:00:43 volumio volumio[1193]: info: Spotify config file written Feb 22 09:00:43 volumio sudo[100599]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 22 09:00:43 volumio sudo[100599]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 22 09:00:43 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 22 09:00:43 volumio systemd[1]: go-librespot-daemon.service: Killing process 100591 (go-librespot) with signal SIGKILL. Feb 22 09:00:43 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 22 09:00:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 22 09:00:43 volumio go-librespot[100601]: go-librespot daemon starting... Feb 22 09:00:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 22 09:00:43 volumio sudo[100599]: pam_unix(sudo:session): session closed for user root Feb 22 09:00:43 volumio go-librespot[100602]: time="2026-02-22T09:00:43+03:00" level=info msg="running go-librespot 0.6.2" Feb 22 09:00:43 volumio go-librespot[100602]: time="2026-02-22T09:00:43+03:00" level=debug msg="app state loaded" Feb 22 09:00:43 volumio go-librespot[100602]: time="2026-02-22T09:00:43+03:00" level=debug msg="stored credentials not found" Feb 22 09:00:43 volumio go-librespot[100602]: time="2026-02-22T09:00:43+03:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 22 09:00:44 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 09:00:44 volumio go-librespot[100602]: time="2026-02-22T09:00:44+03:00" level=debug msg="new websocket client" Feb 22 09:00:44 volumio volumio[1193]: info: Connection to go-librespot Websocket established Feb 22 09:00:44 volumio volumio[1193]: info: go-librespot daemon successfully initialized Feb 22 09:00:44 volumio kernel: usb 3-5: device descriptor read/all, error -110 Feb 22 09:00:44 volumio kernel: usb 3-5: reset high-speed USB device number 7 using ehci-pci Feb 22 09:00:45 volumio go-librespot[100602]: time="2026-02-22T09:00:45+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Feb 22 09:00:45 volumio go-librespot[100602]: time="2026-02-22T09:00:45+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 22 09:00:45 volumio go-librespot[100602]: time="2026-02-22T09:00:45+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 22 09:00:45 volumio go-librespot[100602]: time="2026-02-22T09:00:45+03:00" level=info msg="zeroconf server listening on port 40969" Feb 22 09:00:45 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 736. Feb 22 09:00:45 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 09:00:45 volumio systemd[1]: fusiondsp.service: Consumed 1.345s CPU time. Feb 22 09:00:45 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 09:00:46 volumio volumio[100612]: Traceback (most recent call last): Feb 22 09:00:46 volumio volumio[100612]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 09:00:46 volumio volumio[100612]: from camilladsp import CamillaConnection Feb 22 09:00:46 volumio volumio[100612]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 09:00:46 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 09:00:46 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 09:00:46 volumio systemd[1]: fusiondsp.service: Consumed 1.334s CPU time. Feb 22 09:00:46 volumio volumio[1193]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Feb 22 09:00:46 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Feb 22 09:00:46 volumio volumio[1193]: info: Creating Spotify config file Feb 22 09:00:46 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 09:00:46 volumio volumio[1193]: info: Spotify config file written Feb 22 09:00:46 volumio sudo[100615]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 22 09:00:46 volumio sudo[100615]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 22 09:00:46 volumio volumio[1193]: info: go-librespot daemon successfully initialized Feb 22 09:00:46 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 22 09:00:46 volumio volumio[1193]: info: Connection to go-librespot Websocket closed Feb 22 09:00:46 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 22 09:00:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 22 09:00:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 22 09:00:46 volumio go-librespot[100617]: go-librespot daemon starting... Feb 22 09:00:46 volumio sudo[100615]: pam_unix(sudo:session): session closed for user root Feb 22 09:00:46 volumio go-librespot[100618]: time="2026-02-22T09:00:46+03:00" level=info msg="running go-librespot 0.6.2" Feb 22 09:00:46 volumio go-librespot[100618]: time="2026-02-22T09:00:46+03:00" level=debug msg="app state loaded" Feb 22 09:00:46 volumio go-librespot[100618]: time="2026-02-22T09:00:46+03:00" level=debug msg="stored credentials not found" Feb 22 09:00:46 volumio go-librespot[100618]: time="2026-02-22T09:00:46+03:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 22 09:00:47 volumio volumio[1193]: info: Getting Spotify volume Feb 22 09:00:47 volumio volumio[1193]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Feb 22 09:00:47 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 09:00:47 volumio go-librespot[100618]: time="2026-02-22T09:00:47+03:00" level=debug msg="new websocket client" Feb 22 09:00:47 volumio volumio[1193]: info: Connection to go-librespot Websocket established Feb 22 09:00:47 volumio volumio[1193]: info: CoreCommandRouter::volumioGetState Feb 22 09:00:47 volumio volumio[1193]: info: CorePlayQueue::getTrack 0 Feb 22 09:00:47 volumio go-librespot[100618]: time="2026-02-22T09:00:47+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Feb 22 09:00:47 volumio go-librespot[100618]: time="2026-02-22T09:00:47+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 22 09:00:47 volumio go-librespot[100618]: time="2026-02-22T09:00:47+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 22 09:00:47 volumio go-librespot[100618]: time="2026-02-22T09:00:47+03:00" level=info msg="zeroconf server listening on port 43263" Feb 22 09:00:47 volumio volumio[1193]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Feb 22 09:00:47 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Feb 22 09:00:47 volumio volumio[1193]: info: Creating Spotify config file Feb 22 09:00:47 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 09:00:47 volumio volumio[1193]: info: Spotify config file written Feb 22 09:00:47 volumio sudo[100628]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 22 09:00:47 volumio sudo[100628]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 22 09:00:47 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 22 09:00:47 volumio systemd[1]: go-librespot-daemon.service: Killing process 100626 (go-librespot) with signal SIGKILL. Feb 22 09:00:47 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 22 09:00:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 22 09:00:47 volumio volumio[1193]: info: Connection to go-librespot Websocket closed Feb 22 09:00:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 22 09:00:47 volumio go-librespot[100630]: go-librespot daemon starting... Feb 22 09:00:47 volumio sudo[100628]: pam_unix(sudo:session): session closed for user root Feb 22 09:00:47 volumio go-librespot[100632]: time="2026-02-22T09:00:47+03:00" level=info msg="running go-librespot 0.6.2" Feb 22 09:00:47 volumio go-librespot[100632]: time="2026-02-22T09:00:47+03:00" level=debug msg="app state loaded" Feb 22 09:00:47 volumio go-librespot[100632]: time="2026-02-22T09:00:47+03:00" level=debug msg="stored credentials not found" Feb 22 09:00:47 volumio go-librespot[100632]: time="2026-02-22T09:00:47+03:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 22 09:00:47 volumio volumio[1193]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Feb 22 09:00:47 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Feb 22 09:00:47 volumio volumio[1193]: info: Creating Spotify config file Feb 22 09:00:47 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 09:00:47 volumio volumio[1193]: info: Spotify config file written Feb 22 09:00:47 volumio sudo[100640]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 22 09:00:47 volumio sudo[100640]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 22 09:00:47 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 22 09:00:47 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 22 09:00:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 22 09:00:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 22 09:00:47 volumio go-librespot[100643]: go-librespot daemon starting... Feb 22 09:00:47 volumio sudo[100640]: pam_unix(sudo:session): session closed for user root Feb 22 09:00:47 volumio go-librespot[100644]: time="2026-02-22T09:00:47+03:00" level=info msg="running go-librespot 0.6.2" Feb 22 09:00:47 volumio go-librespot[100644]: time="2026-02-22T09:00:47+03:00" level=debug msg="app state loaded" Feb 22 09:00:47 volumio go-librespot[100644]: time="2026-02-22T09:00:47+03:00" level=debug msg="stored credentials not found" Feb 22 09:00:47 volumio go-librespot[100644]: time="2026-02-22T09:00:47+03:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 22 09:00:47 volumio volumio[1193]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Feb 22 09:00:47 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Feb 22 09:00:47 volumio volumio[1193]: info: Creating Spotify config file Feb 22 09:00:47 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 09:00:47 volumio volumio[1193]: info: Spotify config file written Feb 22 09:00:48 volumio sudo[100653]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 22 09:00:48 volumio sudo[100653]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 22 09:00:48 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 22 09:00:48 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 22 09:00:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 22 09:00:48 volumio systemd[1]: go-librespot-daemon.service: Start request repeated too quickly. Feb 22 09:00:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'start-limit-hit'. Feb 22 09:00:48 volumio systemd[1]: Failed to start go-librespot-daemon.service - go-librespot Daemon. Feb 22 09:00:48 volumio sudo[100653]: pam_unix(sudo:session): session closed for user root Feb 22 09:00:48 volumio volumio[1193]: error: Cannot start Go-librespot Daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Feb 22 09:00:48 volumio volumio[1193]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Feb 22 09:00:48 volumio volumio[1193]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Feb 22 09:00:48 volumio volumio[1193]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Feb 22 09:00:48 volumio volumio[1193]: followed by "systemctl start go-librespot-daemon.service" again. Feb 22 09:00:48 volumio volumio[1193]: error: Error initializing go-librespot daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Feb 22 09:00:48 volumio volumio[1193]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Feb 22 09:00:48 volumio volumio[1193]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Feb 22 09:00:48 volumio volumio[1193]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Feb 22 09:00:48 volumio volumio[1193]: followed by "systemctl start go-librespot-daemon.service" again. Feb 22 09:00:48 volumio volumio[1193]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Feb 22 09:00:48 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Feb 22 09:00:48 volumio volumio[1193]: info: Creating Spotify config file Feb 22 09:00:48 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 09:00:48 volumio volumio[1193]: info: Spotify config file written Feb 22 09:00:48 volumio sudo[100657]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 22 09:00:48 volumio sudo[100657]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 22 09:00:48 volumio systemd[1]: go-librespot-daemon.service: Start request repeated too quickly. Feb 22 09:00:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'start-limit-hit'. Feb 22 09:00:48 volumio systemd[1]: Failed to start go-librespot-daemon.service - go-librespot Daemon. Feb 22 09:00:48 volumio sudo[100657]: pam_unix(sudo:session): session closed for user root Feb 22 09:00:48 volumio volumio[1193]: error: Cannot start Go-librespot Daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Feb 22 09:00:48 volumio volumio[1193]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Feb 22 09:00:48 volumio volumio[1193]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Feb 22 09:00:48 volumio volumio[1193]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Feb 22 09:00:48 volumio volumio[1193]: followed by "systemctl start go-librespot-daemon.service" again. Feb 22 09:00:48 volumio volumio[1193]: error: Error initializing go-librespot daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Feb 22 09:00:48 volumio volumio[1193]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Feb 22 09:00:48 volumio volumio[1193]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Feb 22 09:00:48 volumio volumio[1193]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Feb 22 09:00:48 volumio volumio[1193]: followed by "systemctl start go-librespot-daemon.service" again. Feb 22 09:00:48 volumio volumio[1193]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Feb 22 09:00:48 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Feb 22 09:00:48 volumio volumio[1193]: info: Creating Spotify config file Feb 22 09:00:48 volumio volumio[1193]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 09:00:48 volumio volumio[1193]: info: Spotify config file written Feb 22 09:00:48 volumio sudo[100660]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 22 09:00:48 volumio sudo[100660]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 22 09:00:48 volumio systemd[1]: go-librespot-daemon.service: Start request repeated too quickly. Feb 22 09:00:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'start-limit-hit'. Feb 22 09:00:48 volumio systemd[1]: Failed to start go-librespot-daemon.service - go-librespot Daemon. Feb 22 09:00:48 volumio sudo[100660]: pam_unix(sudo:session): session closed for user root Feb 22 09:00:48 volumio volumio[1193]: error: Cannot start Go-librespot Daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Feb 22 09:00:48 volumio volumio[1193]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Feb 22 09:00:48 volumio volumio[1193]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Feb 22 09:00:48 volumio volumio[1193]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Feb 22 09:00:48 volumio volumio[1193]: followed by "systemctl start go-librespot-daemon.service" again. Feb 22 09:00:48 volumio volumio[1193]: error: Error initializing go-librespot daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Feb 22 09:00:48 volumio volumio[1193]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Feb 22 09:00:48 volumio volumio[1193]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Feb 22 09:00:48 volumio volumio[1193]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Feb 22 09:00:48 volumio volumio[1193]: followed by "systemctl start go-librespot-daemon.service" again. Feb 22 09:00:48 volumio systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 737. Feb 22 09:00:48 volumio systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Feb 22 09:00:48 volumio systemd[1]: fusiondsp.service: Consumed 1.334s CPU time. Feb 22 09:00:48 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Feb 22 09:00:49 volumio volumio[1193]: info: Initializing connection to go-librespot Websocket Feb 22 09:00:49 volumio volumio[1193]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 09:00:49 volumio volumio[1193]: info: go-librespot daemon successfully initialized Feb 22 09:00:50 volumio volumio[100662]: Traceback (most recent call last): Feb 22 09:00:50 volumio volumio[100662]: File "/data/plugins/audio_interface/fusiondsp/cgui/main.py", line 4, in Feb 22 09:00:50 volumio volumio[100662]: from camilladsp import CamillaConnection Feb 22 09:00:50 volumio volumio[100662]: ModuleNotFoundError: No module named 'camilladsp' Feb 22 09:00:50 volumio volumio[1193]: info: Getting Spotify volume Feb 22 09:00:50 volumio volumio[1193]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 22 09:00:50 volumio systemd[1]: fusiondsp.service: Main process exited, code=exited, status=1/FAILURE Feb 22 09:00:50 volumio systemd[1]: fusiondsp.service: Failed with result 'exit-code'. Feb 22 09:00:50 volumio systemd[1]: fusiondsp.service: Consumed 1.360s CPU time. Feb 22 09:00:50 volumio volumio[1193]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 22 09:00:50 volumio volumio[1193]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 22 09:00:50 volumio volumio[1193]: errno: -111, Feb 22 09:00:50 volumio volumio[1193]: code: 'ECONNREFUSED', Feb 22 09:00:50 volumio volumio[1193]: syscall: 'connect', Feb 22 09:00:50 volumio volumio[1193]: address: '127.0.0.1', Feb 22 09:00:50 volumio volumio[1193]: port: 9879, Feb 22 09:00:50 volumio volumio[1193]: response: undefined Feb 22 09:00:50 volumio volumio[1193]: } Feb 22 09:00:50 volumio volumio[1193]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 22 09:00:50 volumio sudo[100693]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-22 08:59' Feb 22 09:00:50 volumio sudo[100693]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:31:57 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="6759e875c98b942866984e844891d6c1"