-- Logs begin at Thu 2025-09-04 20:35:36 CEST, end at Thu 2025-09-04 21:57:06 CEST. -- Sep 04 21:56:01 volumio volumio[1325]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Sep 04 21:56:08 volumio go-librespot[1629]: time="2025-09-04T21:56:08+02:00" level=trace msg="sent dealer ping" Sep 04 21:56:08 volumio go-librespot[1629]: time="2025-09-04T21:56:08+02:00" level=trace msg="received dealer pong" Sep 04 21:56:08 volumio go-librespot[1629]: time="2025-09-04T21:56:08+02:00" level=trace msg="received accesspoint ping" Sep 04 21:56:08 volumio go-librespot[1629]: time="2025-09-04T21:56:08+02:00" level=trace msg="received accesspoint pong ack" Sep 04 21:56:10 volumio volumio[1325]: error: error Sep 04 21:56:12 volumio volumio[1325]: error: error Sep 04 21:56:16 volumio volumio[1325]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/autostart/volumio/buster/armhf Sep 04 21:56:18 volumio volumio[1325]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/autostart/volumio/buster/armhf Sep 04 21:56:18 volumio volumio[1325]: info: Folder /tmp/plugins removed Sep 04 21:56:18 volumio volumio[1325]: info: Check plugin dependencies Sep 04 21:56:18 volumio volumio[1325]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 04 21:56:18 volumio volumio[1325]: info: Checking if plugin already exists Sep 04 21:56:18 volumio volumio[1325]: info: Rename folder Sep 04 21:56:18 volumio volumio[1325]: info: Folder /tmp/downloaded_plugin.zip removed Sep 04 21:56:18 volumio volumio[1325]: info: Move to category Sep 04 21:56:18 volumio volumio[1325]: info: Checking if install.sh is present Sep 04 21:56:18 volumio volumio[1325]: info: Executing install.sh Sep 04 21:56:18 volumio sudo[22061]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/system_controller/autostart/install.sh Sep 04 21:56:18 volumio sudo[22061]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 21:56:18 volumio sudo[22061]: pam_unix(sudo:session): session closed for user root Sep 04 21:56:18 volumio volumio[1325]: info: Install script completed Sep 04 21:56:18 volumio volumio[1325]: info: Adding reference to registry Sep 04 21:56:18 volumio volumio[1325]: info: Done installing plugin. Sep 04 21:56:18 volumio volumio[1325]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 04 21:56:18 volumio volumio[1325]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Sep 04 21:56:18 volumio volumio[1325]: info: Installing autostart Dependencies - no special dependencies needed Sep 04 21:56:18 volumio volumio[1325]: Plugin install end detected on script Sep 04 21:56:18 volumio volumio[1325]: info: Folder /tmp/plugins removed Sep 04 21:56:18 volumio volumio[1325]: info: Folder /tmp/downloaded_plugin.zip removed Sep 04 21:56:18 volumio volumio[1325]: info: Folder /data/temp removed Sep 04 21:56:19 volumio volumio[1325]: info: Enabling plugin autostart Sep 04 21:56:19 volumio volumio[1325]: info: Loading plugin "autostart"... Sep 04 21:56:19 volumio volumio[1325]: info: AutoStart - onVolumioStart - read config.json Sep 04 21:56:19 volumio volumio[1325]: info: PLUGIN START: autostart Sep 04 21:56:19 volumio volumio[1325]: info: AutoStart - onStart Sep 04 21:56:19 volumio volumio[1325]: info: Done. Sep 04 21:56:29 volumio volumio[1325]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Sep 04 21:56:38 volumio go-librespot[1629]: time="2025-09-04T21:56:38+02:00" level=trace msg="sent dealer ping" Sep 04 21:56:38 volumio go-librespot[1629]: time="2025-09-04T21:56:38+02:00" level=trace msg="received dealer pong" Sep 04 21:56:39 volumio volumio[1325]: info: AutoStart - Plugin is starting Sep 04 21:56:39 volumio volumio[1325]: info: CoreCommandRouter::volumioGetQueue Sep 04 21:56:39 volumio volumio[1325]: info: CoreStateMachine::getQueue Sep 04 21:56:39 volumio volumio[1325]: info: CorePlayQueue::getQueue Sep 04 21:56:39 volumio volumio[1325]: info: AutoStart - start playing Sep 04 21:56:39 volumio volumio[1325]: info: AutoStart - start playing with no specific position Sep 04 21:56:39 volumio volumio[1325]: info: CoreCommandRouter::volumioPlay Sep 04 21:56:39 volumio volumio[1325]: info: CoreStateMachine::play index 0 Sep 04 21:56:39 volumio volumio[1325]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 04 21:56:39 volumio volumio[1325]: info: CoreStateMachine::stop Sep 04 21:56:39 volumio volumio[1325]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 04 21:56:39 volumio volumio[1325]: info: CoreStateMachine::stPlaybackTimer Sep 04 21:56:39 volumio volumio[1325]: info: CoreStateMachine::updateTrackBlock Sep 04 21:56:39 volumio volumio[1325]: info: CorePlayQueue::getTrackBlock Sep 04 21:56:39 volumio volumio[1325]: info: CoreStateMachine::pushState Sep 04 21:56:39 volumio volumio[1325]: info: CorePlayQueue::getTrack 4 Sep 04 21:56:39 volumio volumio[1325]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 04 21:56:39 volumio volumio[1325]: info: CoreCommandRouter::volumioPushState Sep 04 21:56:39 volumio volumio[1325]: info: CoreStateMachine::serviceStop Sep 04 21:56:39 volumio volumio[1325]: info: CorePlayQueue::getTrack 4 Sep 04 21:56:39 volumio volumio[1325]: info: CoreCommandRouter::serviceStop Sep 04 21:56:39 volumio volumio[1325]: info: ControllerMpd::stop Sep 04 21:56:39 volumio volumio[1325]: verbose: ControllerMpd::sendMpdCommand stop Sep 04 21:56:39 volumio volumio[1325]: info: [ASDebug] CurState: stop PrevState: play Sep 04 21:56:39 volumio volumio[1325]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Sep 04 21:56:39 volumio volumio[1325]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Sep 04 21:56:39 volumio volumio[1325]: SPOTIFY: SPOTIFY VOLUME 25 Sep 04 21:56:39 volumio volumio[1325]: SPOTIFY: VOLUMIO VOLUME 25 Sep 04 21:56:39 volumio volumio[1325]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 04 21:56:39 volumio volumio[1325]: info: Sep 04 21:56:39 volumio volumio[1325]: ---------------------------- MPD announces state update: player Sep 04 21:56:39 volumio volumio[1325]: info: sendMpdCommand stop took 23 milliseconds Sep 04 21:56:39 volumio volumio[1325]: info: ControllerMpd::getState Sep 04 21:56:39 volumio volumio[1325]: verbose: ControllerMpd::sendMpdCommand status Sep 04 21:56:39 volumio volumio[1325]: info: CoreStateMachine::play index undefined Sep 04 21:56:39 volumio volumio[1325]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 04 21:56:39 volumio volumio[1325]: info: CorePlayQueue::getTrack 0 Sep 04 21:56:39 volumio volumio[1325]: info: CoreStateMachine::startPlaybackTimer Sep 04 21:56:39 volumio volumio[1325]: info: CorePlayQueue::getTrack 0 Sep 04 21:56:39 volumio volumio[1325]: verbose: ControllerMpd::clearAddPlayTracks NAS/music/Xylonite Ivy (Germany) Gothic Melodic/Xylonite Ivy - 2006 - Fraility Of Power/01_stolen_life-amrc.mp3 Sep 04 21:56:39 volumio volumio[1325]: verbose: ControllerMpd::sendMpdCommand stop Sep 04 21:56:39 volumio volumio[1325]: info: sendMpdCommand status took 3 milliseconds Sep 04 21:56:39 volumio volumio[1325]: info: sendMpdCommand stop took 1 milliseconds Sep 04 21:56:39 volumio volumio[1325]: verbose: ControllerMpd::parseState Sep 04 21:56:39 volumio volumio[1325]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 04 21:56:39 volumio volumio[1325]: verbose: ControllerMpd::sendMpdCommand clear Sep 04 21:56:39 volumio volumio[1325]: info: touch_display: Setting screensaver timeout to 0 seconds. Sep 04 21:56:39 volumio volumio[1325]: info: Sep 04 21:56:39 volumio volumio[1325]: ---------------------------- MPD announces system playlist update Sep 04 21:56:39 volumio volumio[1325]: info: Ignoring MPD Status Update Sep 04 21:56:39 volumio volumio[1325]: info: sendMpdCommand playlistinfo took 2 milliseconds Sep 04 21:56:39 volumio volumio[1325]: info: sendMpdCommand clear took 1 milliseconds Sep 04 21:56:39 volumio volumio[1325]: verbose: ControllerMpd::parseTrackInfo Sep 04 21:56:39 volumio volumio[1325]: verbose: ControllerMpd::sendMpdCommand add "NAS/music/Xylonite Ivy (Germany) Gothic Melodic/Xylonite Ivy - 2006 - Fraility Of Power/01_stolen_life-amrc.mp3" Sep 04 21:56:39 volumio volumio[1325]: info: ControllerMpd::pushState Sep 04 21:56:39 volumio volumio[1325]: info: CoreCommandRouter::servicePushState Sep 04 21:56:39 volumio volumio[1325]: info: CoreStateMachine::pushState Sep 04 21:56:39 volumio volumio[1325]: info: CorePlayQueue::getTrack 0 Sep 04 21:56:39 volumio volumio[1325]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 04 21:56:39 volumio volumio[1325]: info: CoreCommandRouter::volumioPushState Sep 04 21:56:39 volumio volumio[1325]: info: CorePlayQueue::getTrack 0 Sep 04 21:56:39 volumio volumio[1325]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Unsettled","artist":"Xylonite Ivy","album":"Frailty of Power","uri":"NAS/music/Xylonite Ivy (Germany) Gothic Melodic/Xylonite Ivy - 2006 - Fraility Of Power/05_unsettled-amrc.mp3","trackType":"mp3"} Sep 04 21:56:39 volumio volumio[1325]: verbose: CURRENT POSITION 0 Sep 04 21:56:39 volumio volumio[1325]: info: CoreStateMachine::syncState stateService stop Sep 04 21:56:39 volumio volumio[1325]: info: CoreStateMachine::syncState currentStatus stop Sep 04 21:56:39 volumio volumio[1325]: info: CoreStateMachine::pushState Sep 04 21:56:39 volumio volumio[1325]: info: CorePlayQueue::getTrack 0 Sep 04 21:56:39 volumio volumio[1325]: info: CoreCommandRouter::volumioPushState Sep 04 21:56:39 volumio volumio[1325]: info: No code Sep 04 21:56:39 volumio volumio[1325]: info: CoreStateMachine::pushState Sep 04 21:56:39 volumio volumio[1325]: info: CorePlayQueue::getTrack 0 Sep 04 21:56:39 volumio volumio[1325]: info: CoreCommandRouter::volumioPushState Sep 04 21:56:39 volumio volumio[1325]: info: ------------------------------ 16ms Sep 04 21:56:39 volumio volumio[1325]: error: updateQueue error: null Sep 04 21:56:39 volumio volumio[1325]: info: Sep 04 21:56:39 volumio volumio[1325]: ---------------------------- MPD announces system playlist update Sep 04 21:56:39 volumio volumio[1325]: info: Ignoring MPD Status Update Sep 04 21:56:39 volumio volumio[1325]: info: ------------------------------ 11ms Sep 04 21:56:39 volumio volumio[1325]: info: sendMpdCommand add "NAS/music/Xylonite Ivy (Germany) Gothic Melodic/Xylonite Ivy - 2006 - Fraility Of Power/01_stolen_life-amrc.mp3" took 10 milliseconds Sep 04 21:56:39 volumio volumio[1325]: verbose: ControllerMpd::sendMpdCommand play Sep 04 21:56:39 volumio volumio[1325]: info: [ASDebug] CurState: stop PrevState: play Sep 04 21:56:39 volumio volumio[1325]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Sep 04 21:56:39 volumio volumio[1325]: info: [ASDebug] CurState: stop PrevState: play Sep 04 21:56:39 volumio volumio[1325]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Sep 04 21:56:39 volumio volumio[1325]: info: [ASDebug] CurState: stop PrevState: play Sep 04 21:56:39 volumio volumio[1325]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Sep 04 21:56:39 volumio volumio[1325]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Sep 04 21:56:39 volumio volumio[1325]: SPOTIFY: SPOTIFY VOLUME 25 Sep 04 21:56:39 volumio volumio[1325]: SPOTIFY: VOLUMIO VOLUME 25 Sep 04 21:56:39 volumio volumio[1325]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 04 21:56:39 volumio volumio[1325]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Sep 04 21:56:39 volumio volumio[1325]: SPOTIFY: SPOTIFY VOLUME 25 Sep 04 21:56:39 volumio volumio[1325]: SPOTIFY: VOLUMIO VOLUME 25 Sep 04 21:56:39 volumio volumio[1325]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 04 21:56:39 volumio volumio[1325]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Sep 04 21:56:39 volumio volumio[1325]: SPOTIFY: SPOTIFY VOLUME 25 Sep 04 21:56:39 volumio volumio[1325]: SPOTIFY: VOLUMIO VOLUME 25 Sep 04 21:56:39 volumio volumio[1325]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 04 21:56:39 volumio volumio[1325]: info: ------------------------------ 6ms Sep 04 21:56:39 volumio volumio[1325]: info: sendMpdCommand play took 5 milliseconds Sep 04 21:56:39 volumio volumio[1325]: info: Sep 04 21:56:39 volumio volumio[1325]: ---------------------------- MPD announces state update: player Sep 04 21:56:39 volumio volumio[1325]: info: ControllerMpd::getState Sep 04 21:56:39 volumio volumio[1325]: verbose: ControllerMpd::sendMpdCommand status Sep 04 21:56:40 volumio volumio[1325]: info: FusionDsp - ---- read samplerate, raw: 192000,S32_LE,2,32 Sep 04 21:56:40 volumio volumio[1325]: info: FusionDsp - ---- read samplerate from file: 192000 Sep 04 21:56:40 volumio volumio[1325]: info: FusionDsp - If filter freq >samplerate/2 then disable it Sep 04 21:56:40 volumio volumio[1325]: info: Sep 04 21:56:40 volumio volumio[1325]: ---------------------------- MPD announces state update: player Sep 04 21:56:40 volumio volumio[1325]: info: sendMpdCommand status took 13 milliseconds Sep 04 21:56:40 volumio volumio[1325]: info: ControllerMpd::getState Sep 04 21:56:40 volumio volumio[1325]: verbose: ControllerMpd::sendMpdCommand status Sep 04 21:56:40 volumio volumio[1325]: verbose: ControllerMpd::parseState Sep 04 21:56:40 volumio volumio[1325]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 04 21:56:40 volumio volumio[1325]: info: sendMpdCommand status took 5 milliseconds Sep 04 21:56:40 volumio volumio[1325]: info: sendMpdCommand playlistinfo took 5 milliseconds Sep 04 21:56:40 volumio volumio[1325]: verbose: ControllerMpd::parseState Sep 04 21:56:40 volumio volumio[1325]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 04 21:56:40 volumio volumio[1325]: verbose: ControllerMpd::parseTrackInfo Sep 04 21:56:40 volumio volumio[1325]: info: ControllerMpd::pushState Sep 04 21:56:40 volumio volumio[1325]: info: CoreCommandRouter::servicePushState Sep 04 21:56:40 volumio volumio[1325]: info: CorePlayQueue::getTrack 0 Sep 04 21:56:40 volumio volumio[1325]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":174,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Stolen Life","artist":"Xylonite Ivy","album":"Frailty of Power","uri":"NAS/music/Xylonite Ivy (Germany) Gothic Melodic/Xylonite Ivy - 2006 - Fraility Of Power/01_stolen_life-amrc.mp3","trackType":"mp3"} Sep 04 21:56:40 volumio volumio[1325]: verbose: CURRENT POSITION 0 Sep 04 21:56:40 volumio volumio[1325]: info: CoreStateMachine::syncState stateService play Sep 04 21:56:40 volumio volumio[1325]: info: CoreStateMachine::syncState currentStatus stop Sep 04 21:56:40 volumio volumio[1325]: info: ------------------------------ 22ms Sep 04 21:56:40 volumio volumio[1325]: info: FusionDsp - {"Reload":{"result":"Ok"}} Sep 04 21:56:40 volumio volumio[1325]: info: sendMpdCommand playlistinfo took 6 milliseconds Sep 04 21:56:40 volumio volumio[1325]: verbose: ControllerMpd::parseTrackInfo Sep 04 21:56:40 volumio volumio[1325]: info: ControllerMpd::pushState Sep 04 21:56:40 volumio volumio[1325]: info: CoreCommandRouter::servicePushState Sep 04 21:56:40 volumio volumio[1325]: info: CorePlayQueue::getTrack 0 Sep 04 21:56:40 volumio volumio[1325]: verbose: STATE SERVICE {"status":"play","position":0,"seek":342,"duration":174,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"160 Kbps","isStreaming":false,"title":"Stolen Life","artist":"Xylonite Ivy","album":"Frailty of Power","uri":"NAS/music/Xylonite Ivy (Germany) Gothic Melodic/Xylonite Ivy - 2006 - Fraility Of Power/01_stolen_life-amrc.mp3","trackType":"mp3"} Sep 04 21:56:40 volumio volumio[1325]: verbose: CURRENT POSITION 0 Sep 04 21:56:40 volumio volumio[1325]: info: CoreStateMachine::syncState stateService play Sep 04 21:56:40 volumio volumio[1325]: info: CoreStateMachine::syncState currentStatus play Sep 04 21:56:40 volumio volumio[1325]: info: Received an update from plugin. extracting info from payload Sep 04 21:56:40 volumio volumio[1325]: info: CoreStateMachine::pushState Sep 04 21:56:40 volumio volumio[1325]: info: CorePlayQueue::getTrack 0 Sep 04 21:56:40 volumio volumio[1325]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 04 21:56:40 volumio volumio[1325]: info: CoreCommandRouter::volumioPushState Sep 04 21:56:40 volumio volumio[1325]: info: CoreStateMachine::pushState Sep 04 21:56:40 volumio volumio[1325]: info: CorePlayQueue::getTrack 0 Sep 04 21:56:40 volumio volumio[1325]: info: CoreCommandRouter::volumioPushState Sep 04 21:56:40 volumio volumio[1325]: info: ------------------------------ 19ms Sep 04 21:56:40 volumio volumio[1325]: info: [ASDebug] CurState: play PrevState: play Sep 04 21:56:40 volumio volumio[1325]: info: [ASDebug] CurState: play PrevState: play Sep 04 21:56:40 volumio volumio[1325]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Sep 04 21:56:40 volumio volumio[1325]: SPOTIFY: SPOTIFY VOLUME 25 Sep 04 21:56:40 volumio volumio[1325]: SPOTIFY: VOLUMIO VOLUME 25 Sep 04 21:56:40 volumio volumio[1325]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 04 21:56:40 volumio volumio[1325]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Sep 04 21:56:40 volumio volumio[1325]: SPOTIFY: SPOTIFY VOLUME 25 Sep 04 21:56:40 volumio volumio[1325]: SPOTIFY: VOLUMIO VOLUME 25 Sep 04 21:56:40 volumio volumio[1325]: SPOTIFY: DELTA VOLUME ENOUGH: false Sep 04 21:56:40 volumio volumio[1325]: info: CoreCommandRouter::volumioGetState Sep 04 21:56:40 volumio volumio[1325]: info: CorePlayQueue::getTrack 0 Sep 04 21:56:48 volumio volumio[1325]: info: Starting Uninstall of plugin audio_interface - fusiondsp Sep 04 21:56:48 volumio volumio[1325]: info: Uninstalling plugin fusiondsp Sep 04 21:56:48 volumio volumio[1325]: info: FusionDsp - Stopping FusionDsp service Sep 04 21:56:48 volumio volumio[1325]: info: camilladsp stopping service pid 19839... Sep 04 21:56:48 volumio volumio[1325]: info: camilladsp service terminated, instance 1 Sep 04 21:56:48 volumio volumio[1325]: info: Disabling plugin fusiondsp Sep 04 21:56:48 volumio sudo[22229]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop fusiondsp.service Sep 04 21:56:48 volumio sudo[22229]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 21:56:48 volumio volumio[1325]: info: Preparing to generate the ALSA configuration file Sep 04 21:56:48 volumio systemd[1]: Stopping FusionDsp Daemon... Sep 04 21:56:48 volumio volumio[1710]: Backend configuration: Sep 04 21:56:48 volumio volumio[1710]: active_config: /data/configuration/audio_interface/fusiondsp/camilladsp.yml Sep 04 21:56:48 volumio volumio[1710]: active_config_txt: null Sep 04 21:56:48 volumio volumio[1710]: camilla_host: 127.0.0.1 Sep 04 21:56:48 volumio volumio[1710]: camilla_port: 9876 Sep 04 21:56:48 volumio volumio[1710]: coeff_dir: /data/INTERNAL/FusionDsp/filters Sep 04 21:56:48 volumio volumio[1710]: config_dir: /data/configuration/audio_interface/fusiondsp Sep 04 21:56:48 volumio volumio[1710]: default_config: /data/configuration/audio_interface/fusiondsp/camilladsp.yml Sep 04 21:56:48 volumio volumio[1710]: log_file: /tmp/camilladsp.log Sep 04 21:56:48 volumio volumio[1710]: on_get_active_config: null Sep 04 21:56:48 volumio volumio[1710]: on_set_active_config: null Sep 04 21:56:48 volumio volumio[1710]: port: 5011 Sep 04 21:56:48 volumio volumio[1710]: supported_capture_types: null Sep 04 21:56:48 volumio volumio[1710]: supported_playback_types: null Sep 04 21:56:48 volumio volumio[1710]: update_config_symlink: false Sep 04 21:56:48 volumio volumio[1710]: update_config_txt: false Sep 04 21:56:48 volumio volumio[1710]: ======== Running on http://0.0.0.0:5011 ======== Sep 04 21:56:48 volumio volumio[1710]: (Press CTRL+C to quit) Sep 04 21:56:48 volumio volumio[1325]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Sep 04 21:56:48 volumio volumio[1325]: info: Reading ALSA contributions from plugins. Sep 04 21:56:48 volumio volumio[1325]: info: Asound.conf file written Sep 04 21:56:48 volumio sudo[22232]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Sep 04 21:56:48 volumio sudo[22232]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 21:56:48 volumio sudo[22232]: pam_unix(sudo:session): session closed for user root Sep 04 21:56:48 volumio volumio[1325]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:Max Overclock PLL:0' : Device or resource busy Sep 04 21:56:48 volumio volumio[1325]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:Max Overclock DSP:0' : Device or resource busy Sep 04 21:56:48 volumio volumio[1325]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:Max Overclock DAC:0' : Device or resource busy Sep 04 21:56:48 volumio volumio[1325]: info: Output device has changed, restarting MPD Sep 04 21:56:48 volumio sudo[22237]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 04 21:56:48 volumio systemd[1]: fusiondsp.service: Succeeded. Sep 04 21:56:48 volumio sudo[22237]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 21:56:48 volumio systemd[1]: Stopped FusionDsp Daemon. Sep 04 21:56:48 volumio sudo[22237]: pam_unix(sudo:session): session closed for user root Sep 04 21:56:48 volumio sudo[22229]: pam_unix(sudo:session): session closed for user root Sep 04 21:56:48 volumio volumio[1325]: info: Output device has changed, restarting Shairport Sync Sep 04 21:56:48 volumio volumio[1325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 21:56:48 volumio volumio[1325]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 04 21:56:48 volumio sudo[22240]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 04 21:56:48 volumio sudo[22240]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 21:56:48 volumio systemd[1]: Stopping Music Player Daemon... Sep 04 21:56:48 volumio volumio[1325]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 04 21:56:48 volumio volumio[1325]: info: Checking if uninstall.sh is present Sep 04 21:56:48 volumio volumio[1325]: info: MPD Permissions set Sep 04 21:56:48 volumio volumio[1325]: info: FusionDsp - Reporting Fusion DSP Disabled Sep 04 21:56:48 volumio volumio[1325]: info: Removing fusiondspeq DSP Signal Path Element Sep 04 21:56:48 volumio volumio[1325]: info: Executing uninstall.sh Sep 04 21:56:48 volumio systemd[1]: mpd.service: Succeeded. Sep 04 21:56:48 volumio systemd[1]: Stopped Music Player Daemon. Sep 04 21:56:48 volumio volumio[1325]: info: CoreCommandRouter::volumioGetState Sep 04 21:56:48 volumio volumio[1325]: info: CorePlayQueue::getTrack 0 Sep 04 21:56:48 volumio volumio[1325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 21:56:48 volumio volumio[1325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 21:56:48 volumio volumio[1325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 21:56:48 volumio volumio[1325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 21:56:48 volumio volumio[1325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 21:56:48 volumio volumio[1325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 21:56:48 volumio volumio[1325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 21:56:48 volumio volumio[1325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 21:56:48 volumio volumio[1325]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 04 21:56:48 volumio systemd[1]: Starting Music Player Daemon... Sep 04 21:56:48 volumio volumio[1325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 04 21:56:48 volumio volumio[1325]: info: Starting Shairport Sync Sep 04 21:56:48 volumio sudo[22248]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/audio_interface/fusiondsp/uninstall.sh Sep 04 21:56:48 volumio sudo[22248]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 21:56:48 volumio sudo[22257]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 04 21:56:48 volumio sudo[22257]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 21:56:48 volumio sudo[22258]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm /lib/systemd/system/fusiondsp.service Sep 04 21:56:48 volumio sudo[22258]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 21:56:48 volumio sudo[22246]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 04 21:56:48 volumio sudo[22246]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 21:56:48 volumio sudo[22258]: pam_unix(sudo:session): session closed for user root Sep 04 21:56:48 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 04 21:56:48 volumio sudo[22246]: pam_unix(sudo:session): session closed for user root Sep 04 21:56:48 volumio systemd[1]: shairport-sync.service: Succeeded. Sep 04 21:56:48 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 04 21:56:48 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 04 21:56:48 volumio sudo[22262]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Sep 04 21:56:48 volumio sudo[22262]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 21:56:48 volumio sudo[22257]: pam_unix(sudo:session): session closed for user root Sep 04 21:56:48 volumio systemd[1]: Reloading. Sep 04 21:56:48 volumio volumio[1325]: info: Shairport-Sync Started Sep 04 21:56:48 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Sep 04 21:56:48 volumio mpd[22263]: Sep 04 21:56 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 04 21:56:48 volumio sudo[22262]: pam_unix(sudo:session): session closed for user root Sep 04 21:56:48 volumio sudo[22248]: pam_unix(sudo:session): session closed for user root Sep 04 21:56:48 volumio volumio[1325]: info: Uninstall script completed Sep 04 21:56:48 volumio volumio[1325]: info: Removing plugin fusiondsp from configuration Sep 04 21:56:48 volumio volumio[1325]: info: Successfully removed fusiondsp configuration files Sep 04 21:56:48 volumio volumio[1325]: info: Plugin folders cleanup Sep 04 21:56:48 volumio volumio[1325]: info: Scanning into folder /volumio/app/plugins/ Sep 04 21:56:48 volumio volumio[1325]: info: Scanning category audio_interface Sep 04 21:56:48 volumio volumio[1325]: info: Scanning category miscellanea Sep 04 21:56:48 volumio volumio[1325]: info: Scanning category music_service Sep 04 21:56:48 volumio volumio[1325]: info: Scanning category plugins.json Sep 04 21:56:48 volumio volumio[1325]: info: Scanning category system_controller Sep 04 21:56:48 volumio volumio[1325]: info: Scanning category user_interface Sep 04 21:56:48 volumio volumio[1325]: info: Scanning into folder /data/plugins/ Sep 04 21:56:48 volumio volumio[1325]: info: Scanning category audio_interface Sep 04 21:56:48 volumio volumio[1325]: info: Cleaning folder for fusiondsp Sep 04 21:56:48 volumio systemd[1]: Started Music Player Daemon. Sep 04 21:56:48 volumio sudo[22240]: pam_unix(sudo:session): session closed for user root Sep 04 21:56:49 volumio volumio[1325]: info: Scanning category music_service Sep 04 21:56:49 volumio volumio[1325]: info: Scanning category system_controller Sep 04 21:56:49 volumio volumio[1325]: info: Scanning category system_hardware Sep 04 21:56:49 volumio volumio[1325]: info: Scanning category user_interface Sep 04 21:56:49 volumio volumio[1325]: info: Plugin folders cleanup completed Sep 04 21:56:49 volumio volumio[1325]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 04 21:56:49 volumio volumio[1325]: info: [{"prettyName":"Spotify","name":"spop","category":"music_service","version":"4.2.2","icon":"fa-spotify","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"YouTube2","name":"youtube2","category":"music_service","version":"1.4.2","icon":"fa-youtube-play","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"YouTube Cast Receiver","name":"ytcr","category":"music_service","version":"1.2.0","icon":"fa-youtube","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Amplifier Switch","name":"ampswitch","category":"system_controller","version":"0.2.1","icon":"fa-power-off","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"AutoStart","name":"autostart","category":"system_controller","version":"3.0.4","icon":"fa-lightbulb-o","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Audiophonics ON/OFF","name":"audiophonicsonoff","category":"system_hardware","version":"1.0.5","icon":"fa fa-cogs","isManuallyInstalled":false,"enabled":true,"active":false},{"prettyName":"Peppy-meter-Basic","name":"peppymeterbasic","category":"user_interface","version":"0.0.3","icon":"fa-bar-chart","isManuallyInstalled":false,"enabled":false,"active":false},{"prettyName":"Peppy-spectrum","name":"peppyspectrum","category":"user_interface","version":"0.0.35","icon":"fa-bar-chart","isManuallyInstalled":false,"enabled":false,"active":false},{"prettyName":"Touch Display","name":"touch_display","category":"user_interface","version":"3.5.1","icon":"fa-hand-pointer-o","isManuallyInstalled":false,"enabled":true,"active":true}] Sep 04 21:56:49 volumio volumio[1325]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Sep 04 21:56:49 volumio volumio[1325]: error: updateQueue error: null Sep 04 21:56:49 volumio volumio[1325]: error: Upnp client error: Error: This socket has been ended by the other party Sep 04 21:56:59 volumio volumio[1325]: error: error Sep 04 21:56:59 volumio volumio[1325]: error: error Sep 04 21:57:05 volumio volumio[1325]: info: ___________ PLUGINS: Run onVolumioReboot Tasks ___________ Sep 04 21:57:05 volumio volumio[1325]: info: PLUGIN onReboot : networkfs Sep 04 21:57:06 volumio sudo[22358]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/umount -f /mnt/NAS/music Sep 04 21:57:06 volumio sudo[22358]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 04 21:57:06 volumio systemd[1]: mnt-NAS-music.mount: Succeeded. Sep 04 21:57:06 volumio sudo[22358]: pam_unix(sudo:session): session closed for user root Sep 04 21:57:06 volumio volumio[1325]: info: PLUGIN onReboot : audiophonicsonoff Sep 04 21:57:06 volumio volumio[1325]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 04 21:57:06 volumio volumio[1325]: TypeError: Cannot read property 'writeSync' of undefined Sep 04 21:57:06 volumio volumio[1325]: at ControllerAudiophonicsOnOff.onVolumioReboot (/data/plugins/system_hardware/audiophonicsonoff/index.js:40:25) Sep 04 21:57:06 volumio volumio[1325]: at PluginManager.onVolumioRebootPlugin (/volumio/app/pluginmanager.js:684:30) Sep 04 21:57:06 volumio volumio[1325]: at HashMap. (/volumio/app/pluginmanager.js:668:31) Sep 04 21:57:06 volumio volumio[1325]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Sep 04 21:57:06 volumio volumio[1325]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Sep 04 21:57:06 volumio volumio[1325]: at PluginManager.onVolumioReboot (/volumio/app/pluginmanager.js:666:20) Sep 04 21:57:06 volumio volumio[1325]: at CoreCommandRouter.reboot (/volumio/app/index.js:1350:22) Sep 04 21:57:06 volumio volumio[1325]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:870:33) Sep 04 21:57:06 volumio volumio[1325]: at Socket.emit (events.js:315:20) Sep 04 21:57:06 volumio volumio[1325]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Sep 04 21:57:06 volumio volumio[1325]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Sep 04 21:57:06 volumio volumio[1325]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 04 21:57:06 volumio sudo[22371]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-04 21:56 Sep 04 21:57:06 volumio sudo[22371]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="29866754e5f1d7e4d0f581c10d9f22852f6f21db" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:25:36 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="cf6e14681b2ecbbdc9a62186b0f3114c"