-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Fri 2025-01-17 09:28:24 CET. -- Jan 17 09:27:00 chocopi volumio[874]: info: Downloading https://files.pythonhosted.org/packages/38/71/c13ea695a4393639830bf96baea956538ba7a9d06fcce7cef10bfff20f72/importlib_resources-5.12.0-py3-none-any.whl Jan 17 09:27:00 chocopi volumio[874]: info: Collecting pyrsistent!=0.17.0,!=0.17.1,!=0.17.2,>=0.14.0 (from jsonschema->camilladsp-plot==1.0.2) Jan 17 09:27:26 chocopi volumio[874]: info: Downloading https://www.piwheels.org/simple/pyrsistent/pyrsistent-0.19.3-cp37-cp37m-linux_armv7l.whl (83kB) Jan 17 09:27:26 chocopi volumio[874]: info: Collecting zipp>=0.5 (from importlib-metadata; python_version < "3.8"->jsonschema->camilladsp-plot==1.0.2) Jan 17 09:27:34 chocopi volumio[874]: info: Downloading https://files.pythonhosted.org/packages/5b/fa/c9e82bbe1af6266adf08afb563905eb87cab83fde00a0a08963510621047/zipp-3.15.0-py3-none-any.whl Jan 17 09:27:34 chocopi volumio[874]: info: Building wheels for collected packages: camilladsp-plot Jan 17 09:27:34 chocopi volumio[874]: info: Running setup.py bdist_wheel for camilladsp-plot: started Jan 17 09:27:35 chocopi volumio[874]: info: Running setup.py bdist_wheel for camilladsp-plot: finished with status 'done' Jan 17 09:27:35 chocopi volumio[874]: info: Stored in directory: /tmp/pip-ephem-wheel-cache-_idax5r2/wheels/11/e1/43/8275af2f537d569c7097d202b4955f9aec629859be39dab2e9 Jan 17 09:27:35 chocopi volumio[874]: info: Successfully built camilladsp-plot Jan 17 09:27:36 chocopi volumio[874]: info: Installing collected packages: typing-extensions, zipp, importlib-metadata, pkgutil-resolve-name, importlib-resources, pyrsistent, jsonschema, camilladsp-plot Jan 17 09:27:37 chocopi volumio[874]: info: Successfully installed camilladsp-plot-1.0.2 importlib-metadata-6.7.0 importlib-resources-5.12.0 jsonschema-4.17.3 pkgutil-resolve-name-1.3.10 pyrsistent-0.19.3 typing-extensions-4.7.1 zipp-3.15.0 Jan 17 09:27:37 chocopi volumio[874]: info: copying hw detection script Jan 17 09:27:37 chocopi volumio[874]: info: Detected cpu architecture as armv7l Jan 17 09:27:39 chocopi volumio[874]: info: camilladsp Jan 17 09:27:39 chocopi sudo[4718]: root : TTY=unknown ; PWD=/tmp ; USER=root ; COMMAND=/bin/cp /data/plugins/audio_interface/fusiondsp/c/hw_params_arm /data/plugins/audio_interface/fusiondsp/hw_params Jan 17 09:27:39 chocopi sudo[4718]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 17 09:27:39 chocopi sudo[4718]: pam_unix(sudo:session): session closed for user root Jan 17 09:27:39 chocopi sudo[4720]: root : TTY=unknown ; PWD=/tmp ; USER=root ; COMMAND=/bin/chmod +x /data/plugins/audio_interface/fusiondsp/hw_params Jan 17 09:27:39 chocopi sudo[4720]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 17 09:27:39 chocopi sudo[4720]: pam_unix(sudo:session): session closed for user root Jan 17 09:27:39 chocopi sudo[4722]: root : TTY=unknown ; PWD=/tmp ; USER=root ; COMMAND=/usr/bin/apt-get -y install drc Jan 17 09:27:39 chocopi sudo[4722]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 17 09:27:39 chocopi volumio[874]: info: Reading package lists... Jan 17 09:27:40 chocopi volumio[874]: info: Building dependency tree... Jan 17 09:27:40 chocopi volumio[874]: info: Reading state information... Jan 17 09:27:41 chocopi volumio[874]: info: The following NEW packages will be installed: Jan 17 09:27:41 chocopi volumio[874]: info: drc Jan 17 09:27:42 chocopi volumio[874]: info: 0 upgraded, 1 newly installed, 0 to remove and 2 not upgraded. Jan 17 09:27:42 chocopi volumio[874]: info: Need to get 112 kB of archives. Jan 17 09:27:42 chocopi volumio[874]: info: After this operation, 512 kB of additional disk space will be used. Jan 17 09:27:42 chocopi volumio[874]: info: Get:1 http://mirror.de.leaseweb.net/raspbian/raspbian buster/main armhf drc armhf 3.2.2~dfsg0-2 [112 kB] Jan 17 09:27:43 chocopi volumio[874]: info: Fetched 112 kB in 0s (288 kB/s) Jan 17 09:27:43 chocopi volumio[874]: info: Selecting previously unselected package drc. Jan 17 09:27:44 chocopi volumio[874]: [620B blob data] Jan 17 09:27:44 chocopi volumio[874]: info: Preparing to unpack .../drc_3.2.2~dfsg0-2_armhf.deb ... Jan 17 09:27:44 chocopi volumio[874]: info: Unpacking drc (3.2.2~dfsg0-2) ... Jan 17 09:27:45 chocopi volumio[874]: info: Setting up drc (3.2.2~dfsg0-2) ... Jan 17 09:27:46 chocopi sudo[4722]: pam_unix(sudo:session): session closed for user root Jan 17 09:27:46 chocopi sudo[2985]: pam_unix(sudo:session): session closed for user root Jan 17 09:27:46 chocopi volumio[874]: Plugin install end detected on script Jan 17 09:27:46 chocopi volumio[874]: info: Install script completed Jan 17 09:27:46 chocopi volumio[874]: info: Adding reference to registry Jan 17 09:27:46 chocopi volumio[874]: info: Done installing plugin. Jan 17 09:27:46 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 17 09:27:46 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 17 09:27:46 chocopi volumio[874]: info: Folder /tmp/plugins removed Jan 17 09:27:46 chocopi volumio[874]: info: Folder /tmp/downloaded_plugin.zip removed Jan 17 09:27:46 chocopi volumio[874]: info: Folder /data/temp removed Jan 17 09:27:47 chocopi volumio[874]: error: Failed to check for new versions for plugin YouTube Music: Error: Invalid argument not valid semver ('' received) Jan 17 09:27:52 chocopi volumio[874]: info: Enabling plugin fusiondsp Jan 17 09:27:52 chocopi volumio[874]: info: Loading plugin "fusiondsp"... Jan 17 09:27:53 chocopi volumio[874]: info: Preparing to generate the ALSA configuration file Jan 17 09:27:53 chocopi volumio[874]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jan 17 09:27:53 chocopi volumio[874]: info: Reading ALSA contributions from plugins. Jan 17 09:27:53 chocopi volumio[874]: info: Asound.conf file written Jan 17 09:27:53 chocopi sudo[4776]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Jan 17 09:27:53 chocopi sudo[4776]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 17 09:27:53 chocopi sudo[4776]: pam_unix(sudo:session): session closed for user root Jan 17 09:27:53 chocopi volumio[874]: info: Output device has changed, restarting MPD Jan 17 09:27:53 chocopi sudo[4781]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 17 09:27:53 chocopi sudo[4781]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 17 09:27:53 chocopi sudo[4781]: pam_unix(sudo:session): session closed for user root Jan 17 09:27:53 chocopi volumio[874]: info: Output device has changed, restarting Shairport Sync Jan 17 09:27:53 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 17 09:27:53 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 17 09:27:53 chocopi sudo[4784]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 17 09:27:53 chocopi sudo[4784]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 17 09:27:54 chocopi systemd[1]: Stopping Music Player Daemon... Jan 17 09:27:54 chocopi volumio[874]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 17 09:27:54 chocopi volumio[874]: info: PLUGIN START: fusiondsp Jan 17 09:27:54 chocopi volumio[874]: info: Loading i18n strings for locale en Jan 17 09:27:54 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 17 09:27:54 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 17 09:27:54 chocopi volumio[874]: info: FusionDsp - mixtype--------------------- Hardware Jan 17 09:27:54 chocopi volumio[874]: info: Preparing to generate the ALSA configuration file Jan 17 09:27:54 chocopi volumio[874]: info: Done. Jan 17 09:27:54 chocopi systemd[1]: mpd.service: Succeeded. Jan 17 09:27:54 chocopi systemd[1]: Stopped Music Player Daemon. Jan 17 09:27:54 chocopi volumio[874]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jan 17 09:27:54 chocopi volumio[874]: info: Reading ALSA contributions from plugins. Jan 17 09:27:54 chocopi volumio[874]: info: MPD Permissions set Jan 17 09:27:54 chocopi volumio[874]: info: CoreCommandRouter::volumioGetState Jan 17 09:27:54 chocopi volumio[874]: info: CorePlayQueue::getTrack 0 Jan 17 09:27:54 chocopi volumio[874]: info: Starting Shairport Sync Jan 17 09:27:54 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 17 09:27:54 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 17 09:27:54 chocopi sudo[4791]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 17 09:27:54 chocopi sudo[4791]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 17 09:27:54 chocopi systemd[1]: Starting Music Player Daemon... Jan 17 09:27:54 chocopi systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 17 09:27:54 chocopi systemd[1]: shairport-sync.service: Succeeded. Jan 17 09:27:54 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 17 09:27:54 chocopi systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 17 09:27:54 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 17 09:27:54 chocopi volumio[874]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 17 09:27:54 chocopi systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 17 09:27:54 chocopi sudo[4791]: pam_unix(sudo:session): session closed for user root Jan 17 09:27:54 chocopi volumio[874]: info: Asound.conf file unchanged, so no further update is needed Jan 17 09:27:54 chocopi volumio[874]: info: Output device has changed, restarting MPD Jan 17 09:27:54 chocopi sudo[4799]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 17 09:27:54 chocopi sudo[4799]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 17 09:27:54 chocopi sudo[4799]: pam_unix(sudo:session): session closed for user root Jan 17 09:27:54 chocopi volumio[874]: info: Output device has changed, restarting Shairport Sync Jan 17 09:27:54 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 17 09:27:54 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 17 09:27:54 chocopi sudo[4802]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 17 09:27:54 chocopi sudo[4802]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 17 09:27:54 chocopi sudo[4789]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 17 09:27:54 chocopi sudo[4789]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 17 09:27:54 chocopi sudo[4789]: pam_unix(sudo:session): session closed for user root Jan 17 09:27:54 chocopi volumio[874]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 17 09:27:54 chocopi volumio[874]: info: MPD Permissions set Jan 17 09:27:54 chocopi volumio[874]: info: Shairport-Sync Started Jan 17 09:27:54 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 17 09:27:54 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 17 09:27:54 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 17 09:27:54 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 17 09:27:54 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 17 09:27:54 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 17 09:27:54 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 17 09:27:54 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 17 09:27:54 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 17 09:27:54 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 17 09:27:54 chocopi systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Jan 17 09:27:54 chocopi systemd[1]: mpd.service: Succeeded. Jan 17 09:27:54 chocopi systemd[1]: Stopped Music Player Daemon. Jan 17 09:27:54 chocopi systemd[1]: Starting Music Player Daemon... Jan 17 09:27:54 chocopi sudo[4815]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 17 09:27:54 chocopi sudo[4815]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 17 09:27:54 chocopi sudo[4815]: pam_unix(sudo:session): session closed for user root Jan 17 09:27:54 chocopi volumio[874]: info: Starting Shairport Sync Jan 17 09:27:54 chocopi sudo[4819]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 17 09:27:54 chocopi sudo[4819]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 17 09:27:54 chocopi systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 17 09:27:54 chocopi systemd[1]: shairport-sync.service: Succeeded. Jan 17 09:27:54 chocopi systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 17 09:27:54 chocopi systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 17 09:27:54 chocopi sudo[4819]: pam_unix(sudo:session): session closed for user root Jan 17 09:27:54 chocopi volumio[874]: info: Shairport-Sync Started Jan 17 09:27:55 chocopi mpd[4817]: Jan 17 09:27 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 17 09:27:55 chocopi systemd[1]: Started Music Player Daemon. Jan 17 09:27:55 chocopi sudo[4802]: pam_unix(sudo:session): session closed for user root Jan 17 09:27:55 chocopi sudo[4784]: pam_unix(sudo:session): session closed for user root Jan 17 09:27:56 chocopi volumio[874]: error: MPD error: The expression evaluated to a falsy value: Jan 17 09:27:56 chocopi volumio[874]: assert.ok(self.idling) Jan 17 09:27:56 chocopi volumio[874]: error: The expression evaluated to a falsy value: Jan 17 09:27:56 chocopi volumio[874]: assert.ok(self.idling) Jan 17 09:27:56 chocopi volumio[874]: error: updateQueue error: null Jan 17 09:27:56 chocopi volumio[874]: info: camilladsp spawned new process with pid 4832, instance 1, run: true Jan 17 09:27:56 chocopi volumio[874]: info: camilladsp service started and running in background, instance 1 Jan 17 09:27:56 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 17 09:27:56 chocopi volumio[874]: info: FusionDsp - AAAAAAAAAAAAAA-> 22050 44100 48000 88200 96000 176400 192000 <-AAAAAAAAAAAAA Jan 17 09:27:56 chocopi volumio[874]: info: FusionDsp loaded Jan 17 09:27:56 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 17 09:27:56 chocopi sudo[4838]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Jan 17 09:27:56 chocopi sudo[4838]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 17 09:27:56 chocopi volumio[874]: info: FusionDsp - Reporting Fusion DSP Enabled Jan 17 09:27:56 chocopi volumio[874]: info: Adding Signal Path Element [object Object] Jan 17 09:27:56 chocopi volumio[874]: info: Adding fusiondspeq DSP Signal Path Element Jan 17 09:27:56 chocopi volumio[874]: info: FusionDsp - ---- installed callbackRead Jan 17 09:27:56 chocopi volumio[874]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jan 17 09:27:56 chocopi volumio[874]: error: FusionDsp - WebSocket error: [object Object] Jan 17 09:27:56 chocopi volumio[874]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Jan 17 09:27:56 chocopi systemd[1]: Started FusionDsp Daemon. Jan 17 09:27:56 chocopi sudo[4838]: pam_unix(sudo:session): session closed for user root Jan 17 09:27:57 chocopi volumio[874]: 0+0 records in Jan 17 09:27:57 chocopi volumio[874]: 0+0 records out Jan 17 09:27:57 chocopi volumio[874]: 0 bytes copied, 0.000152082 s, 0.0 kB/s Jan 17 09:27:57 chocopi volumio[874]: info: camilladsp spawned new process with pid 4843, instance 1, run: true Jan 17 09:27:59 chocopi volumio[874]: info: CoreCommandRouter::volumioGetState Jan 17 09:27:59 chocopi volumio[874]: info: CorePlayQueue::getTrack 0 Jan 17 09:28:00 chocopi volumio[874]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 17 09:28:00 chocopi volumio[874]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 17 09:28:00 chocopi volumio[874]: info: Retrieving Cloud Streaming UI Jan 17 09:28:00 chocopi volumio[874]: info: Getting Tidal Cloud Configuration Jan 17 09:28:00 chocopi volumio[874]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 17 09:28:00 chocopi volumio[874]: info: Getting Qobuz Cloud Configuration Jan 17 09:28:00 chocopi volumio[874]: info: Asking plugin for UI Config Jan 17 09:28:00 chocopi volumio[874]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 17 09:28:00 chocopi volumio[874]: info: Getting Spotify Cloud Configuration Jan 17 09:28:00 chocopi volumio[874]: info: Asking plugin for UI Config Jan 17 09:28:00 chocopi volumio[874]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 17 09:28:00 chocopi volumio[874]: info: Saving Spotify Acccount Jan 17 09:28:00 chocopi volumio[874]: info: Got Tidal Cloud Configuration Jan 17 09:28:00 chocopi volumio[874]: info: Got it Jan 17 09:28:00 chocopi volumio[874]: info: Got it Jan 17 09:28:00 chocopi volumio[874]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Jan 17 09:28:00 chocopi volumio[874]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 17 09:28:00 chocopi volumio[874]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Jan 17 09:28:00 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jan 17 09:28:00 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 17 09:28:00 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 17 09:28:00 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 17 09:28:00 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 17 09:28:00 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 17 09:28:00 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 17 09:28:00 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 17 09:28:00 chocopi volumio[874]: info: CoreCommandRouter::volumioGetBrowseSources Jan 17 09:28:00 chocopi volumio[874]: info: CoreCommandRouter::volumioGetBrowseSources Jan 17 09:28:00 chocopi volumio[874]: info: CoreCommandRouter::volumioGetBrowseSources Jan 17 09:28:00 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 17 09:28:00 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jan 17 09:28:03 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: mpd , rescanDb Jan 17 09:28:03 chocopi volumio[874]: verbose: ControllerMpd::sendMpdCommand rescan Jan 17 09:28:03 chocopi volumio[874]: verbose: ControllerMpd::sendMpdCommand status Jan 17 09:28:03 chocopi volumio[874]: info: Jan 17 09:28:03 chocopi volumio[874]: ---------------------------- MPD announces state update: update Jan 17 09:28:03 chocopi volumio[874]: info: sendMpdCommand rescan took 13 milliseconds Jan 17 09:28:03 chocopi volumio[874]: info: ControllerMpd::getState Jan 17 09:28:03 chocopi volumio[874]: verbose: ControllerMpd::sendMpdCommand status Jan 17 09:28:03 chocopi volumio[874]: verbose: ControllerMpd::sendMpdCommand status Jan 17 09:28:03 chocopi volumio[874]: info: Jan 17 09:28:03 chocopi volumio[874]: ---------------------------- MPD announces state update: update Jan 17 09:28:03 chocopi volumio[874]: info: ControllerMpd::getState Jan 17 09:28:03 chocopi volumio[874]: verbose: ControllerMpd::sendMpdCommand status Jan 17 09:28:03 chocopi volumio[874]: verbose: ControllerMpd::sendMpdCommand status Jan 17 09:28:03 chocopi volumio[874]: info: Jan 17 09:28:03 chocopi volumio[874]: ---------------------------- MPD announces state update: update Jan 17 09:28:03 chocopi volumio[874]: info: ControllerMpd::getState Jan 17 09:28:03 chocopi volumio[874]: verbose: ControllerMpd::sendMpdCommand status Jan 17 09:28:03 chocopi volumio[874]: info: sendMpdCommand status took 11 milliseconds Jan 17 09:28:03 chocopi volumio[874]: info: sendMpdCommand status took 8 milliseconds Jan 17 09:28:03 chocopi volumio[874]: info: sendMpdCommand status took 7 milliseconds Jan 17 09:28:03 chocopi volumio[874]: info: sendMpdCommand status took 6 milliseconds Jan 17 09:28:03 chocopi volumio[874]: verbose: ControllerMpd::parseState Jan 17 09:28:04 chocopi volumio[874]: info: Command Router : Notfying DB Updatefalse Jan 17 09:28:04 chocopi volumio[874]: info: CoreCommandRouter::Close All Modals sent Jan 17 09:28:04 chocopi volumio[874]: verbose: ControllerMpd::parseState Jan 17 09:28:04 chocopi volumio[874]: verbose: ControllerMpd::parseState Jan 17 09:28:04 chocopi volumio[874]: info: Command Router : Notfying DB Updatefalse Jan 17 09:28:04 chocopi volumio[874]: info: CoreCommandRouter::Close All Modals sent Jan 17 09:28:04 chocopi volumio[874]: verbose: ControllerMpd::parseState Jan 17 09:28:04 chocopi volumio[874]: info: ControllerMpd::pushState Jan 17 09:28:04 chocopi volumio[874]: info: CoreCommandRouter::servicePushState Jan 17 09:28:04 chocopi volumio[874]: info: CoreStateMachine::pushState Jan 17 09:28:04 chocopi volumio[874]: info: CorePlayQueue::getTrack 0 Jan 17 09:28:04 chocopi volumio[874]: info: CoreCommandRouter::volumioPushState Jan 17 09:28:04 chocopi volumio[874]: info: CorePlayQueue::getTrack 0 Jan 17 09:28:04 chocopi volumio[874]: 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} Jan 17 09:28:04 chocopi volumio[874]: verbose: CURRENT POSITION 0 Jan 17 09:28:04 chocopi volumio[874]: info: CoreStateMachine::syncState stateService stop Jan 17 09:28:04 chocopi volumio[874]: info: CoreStateMachine::syncState currentStatus stop Jan 17 09:28:04 chocopi volumio[874]: info: CoreStateMachine::pushState Jan 17 09:28:04 chocopi volumio[874]: info: CorePlayQueue::getTrack 0 Jan 17 09:28:04 chocopi volumio[874]: info: CoreCommandRouter::volumioPushState Jan 17 09:28:04 chocopi volumio[874]: info: No code Jan 17 09:28:04 chocopi volumio[874]: info: CoreStateMachine::pushState Jan 17 09:28:04 chocopi volumio[874]: info: CorePlayQueue::getTrack 0 Jan 17 09:28:04 chocopi volumio[874]: info: CoreCommandRouter::volumioPushState Jan 17 09:28:04 chocopi volumio[874]: info: ControllerMpd::pushState Jan 17 09:28:04 chocopi volumio[874]: info: CoreCommandRouter::servicePushState Jan 17 09:28:04 chocopi volumio[874]: info: CoreStateMachine::pushState Jan 17 09:28:04 chocopi volumio[874]: info: CorePlayQueue::getTrack 0 Jan 17 09:28:04 chocopi volumio[874]: info: CoreCommandRouter::volumioPushState Jan 17 09:28:04 chocopi volumio[874]: info: CorePlayQueue::getTrack 0 Jan 17 09:28:04 chocopi volumio[874]: 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} Jan 17 09:28:04 chocopi volumio[874]: verbose: CURRENT POSITION 0 Jan 17 09:28:04 chocopi volumio[874]: info: CoreStateMachine::syncState stateService stop Jan 17 09:28:04 chocopi volumio[874]: info: CoreStateMachine::syncState currentStatus stop Jan 17 09:28:04 chocopi volumio[874]: info: CoreStateMachine::pushState Jan 17 09:28:04 chocopi volumio[874]: info: CorePlayQueue::getTrack 0 Jan 17 09:28:04 chocopi volumio[874]: info: CoreCommandRouter::volumioPushState Jan 17 09:28:04 chocopi volumio[874]: info: No code Jan 17 09:28:04 chocopi volumio[874]: info: CoreStateMachine::pushState Jan 17 09:28:04 chocopi volumio[874]: info: CorePlayQueue::getTrack 0 Jan 17 09:28:04 chocopi volumio[874]: info: CoreCommandRouter::volumioPushState Jan 17 09:28:04 chocopi volumio[874]: info: ------------------------------ 267ms Jan 17 09:28:04 chocopi volumio[874]: info: ------------------------------ 263ms Jan 17 09:28:04 chocopi volumio[874]: verbose: ControllerMpd::sendMpdCommand status Jan 17 09:28:04 chocopi volumio[874]: info: Jan 17 09:28:04 chocopi volumio[874]: ---------------------------- MPD announces state update: update Jan 17 09:28:04 chocopi volumio[874]: info: ControllerMpd::getState Jan 17 09:28:04 chocopi volumio[874]: verbose: ControllerMpd::sendMpdCommand status Jan 17 09:28:04 chocopi volumio[874]: info: sendMpdCommand status took 265 milliseconds Jan 17 09:28:04 chocopi volumio[874]: info: sendMpdCommand status took 264 milliseconds Jan 17 09:28:04 chocopi volumio[874]: info: sendMpdCommand status took 5 milliseconds Jan 17 09:28:04 chocopi volumio[874]: info: sendMpdCommand status took 4 milliseconds Jan 17 09:28:04 chocopi volumio[874]: verbose: ControllerMpd::parseState Jan 17 09:28:04 chocopi volumio[874]: info: Command Router : Notfying DB Updatefalse Jan 17 09:28:04 chocopi volumio[874]: info: CoreCommandRouter::Close All Modals sent Jan 17 09:28:04 chocopi volumio[874]: verbose: ControllerMpd::parseState Jan 17 09:28:04 chocopi volumio[874]: verbose: ControllerMpd::parseState Jan 17 09:28:04 chocopi volumio[874]: info: Command Router : Notfying DB Updatefalse Jan 17 09:28:04 chocopi volumio[874]: info: CoreCommandRouter::Close All Modals sent Jan 17 09:28:04 chocopi volumio[874]: verbose: ControllerMpd::parseState Jan 17 09:28:04 chocopi volumio[874]: info: ControllerMpd::pushState Jan 17 09:28:04 chocopi volumio[874]: info: CoreCommandRouter::servicePushState Jan 17 09:28:04 chocopi volumio[874]: info: CoreStateMachine::pushState Jan 17 09:28:04 chocopi volumio[874]: info: CorePlayQueue::getTrack 0 Jan 17 09:28:04 chocopi volumio[874]: info: CoreCommandRouter::volumioPushState Jan 17 09:28:04 chocopi volumio[874]: info: CorePlayQueue::getTrack 0 Jan 17 09:28:04 chocopi volumio[874]: 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} Jan 17 09:28:04 chocopi volumio[874]: verbose: CURRENT POSITION 0 Jan 17 09:28:04 chocopi volumio[874]: info: CoreStateMachine::syncState stateService stop Jan 17 09:28:04 chocopi volumio[874]: info: CoreStateMachine::syncState currentStatus stop Jan 17 09:28:04 chocopi volumio[874]: info: CoreStateMachine::pushState Jan 17 09:28:04 chocopi volumio[874]: info: CorePlayQueue::getTrack 0 Jan 17 09:28:04 chocopi volumio[874]: info: CoreCommandRouter::volumioPushState Jan 17 09:28:04 chocopi volumio[874]: info: No code Jan 17 09:28:04 chocopi volumio[874]: info: CoreStateMachine::pushState Jan 17 09:28:04 chocopi volumio[874]: info: CorePlayQueue::getTrack 0 Jan 17 09:28:04 chocopi volumio[874]: info: CoreCommandRouter::volumioPushState Jan 17 09:28:04 chocopi volumio[874]: info: ControllerMpd::pushState Jan 17 09:28:04 chocopi volumio[874]: info: CoreCommandRouter::servicePushState Jan 17 09:28:04 chocopi volumio[874]: info: CoreStateMachine::pushState Jan 17 09:28:04 chocopi volumio[874]: info: CorePlayQueue::getTrack 0 Jan 17 09:28:04 chocopi volumio[874]: info: CoreCommandRouter::volumioPushState Jan 17 09:28:04 chocopi volumio[874]: info: CorePlayQueue::getTrack 0 Jan 17 09:28:04 chocopi volumio[874]: 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} Jan 17 09:28:04 chocopi volumio[874]: verbose: CURRENT POSITION 0 Jan 17 09:28:04 chocopi volumio[874]: info: CoreStateMachine::syncState stateService stop Jan 17 09:28:04 chocopi volumio[874]: info: CoreStateMachine::syncState currentStatus stop Jan 17 09:28:04 chocopi volumio[874]: info: CoreStateMachine::pushState Jan 17 09:28:04 chocopi volumio[874]: info: CorePlayQueue::getTrack 0 Jan 17 09:28:04 chocopi volumio[874]: info: CoreCommandRouter::volumioPushState Jan 17 09:28:04 chocopi volumio[874]: info: No code Jan 17 09:28:04 chocopi volumio[874]: info: CoreStateMachine::pushState Jan 17 09:28:04 chocopi volumio[874]: info: CorePlayQueue::getTrack 0 Jan 17 09:28:04 chocopi volumio[874]: info: CoreCommandRouter::volumioPushState Jan 17 09:28:04 chocopi volumio[874]: info: ------------------------------ 401ms Jan 17 09:28:04 chocopi volumio[874]: info: ------------------------------ 141ms Jan 17 09:28:04 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 17 09:28:08 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 17 09:28:12 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 17 09:28:13 chocopi volumio[874]: info: CoreCommandRouter::volumioGetState Jan 17 09:28:13 chocopi volumio[874]: info: CorePlayQueue::getTrack 0 Jan 17 09:28:16 chocopi volumio[874]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 17 09:28:16 chocopi volumio[874]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 17 09:28:16 chocopi volumio[874]: info: Retrieving Cloud Streaming UI Jan 17 09:28:16 chocopi volumio[874]: info: Getting Tidal Cloud Configuration Jan 17 09:28:16 chocopi volumio[874]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 17 09:28:16 chocopi volumio[874]: info: Getting Qobuz Cloud Configuration Jan 17 09:28:16 chocopi volumio[874]: info: Asking plugin for UI Config Jan 17 09:28:16 chocopi volumio[874]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 17 09:28:16 chocopi volumio[874]: info: Getting Spotify Cloud Configuration Jan 17 09:28:16 chocopi volumio[874]: info: Asking plugin for UI Config Jan 17 09:28:16 chocopi volumio[874]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 17 09:28:16 chocopi volumio[874]: info: Saving Spotify Acccount Jan 17 09:28:16 chocopi volumio[874]: info: Got Tidal Cloud Configuration Jan 17 09:28:16 chocopi volumio[874]: info: Got it Jan 17 09:28:16 chocopi volumio[874]: info: Got it Jan 17 09:28:16 chocopi volumio[874]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Jan 17 09:28:16 chocopi volumio[874]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 17 09:28:16 chocopi volumio[874]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Jan 17 09:28:16 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jan 17 09:28:16 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 17 09:28:16 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 17 09:28:16 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 17 09:28:16 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 17 09:28:16 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 17 09:28:16 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 17 09:28:16 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 17 09:28:16 chocopi volumio[874]: info: CoreCommandRouter::volumioGetBrowseSources Jan 17 09:28:16 chocopi volumio[874]: info: CoreCommandRouter::volumioGetBrowseSources Jan 17 09:28:16 chocopi volumio[874]: info: CoreCommandRouter::volumioGetBrowseSources Jan 17 09:28:16 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 17 09:28:16 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jan 17 09:28:20 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 17 09:28:22 chocopi volumio[874]: info: Disabling MyMusic plugin upnp Jan 17 09:28:22 chocopi sudo[4912]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Jan 17 09:28:22 chocopi sudo[4912]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 17 09:28:22 chocopi systemd[1]: Stopping UPnP Renderer front-end to MPD... Jan 17 09:28:22 chocopi volumio[874]: error: Upnp client error: Error: This socket has been ended by the other party Jan 17 09:28:24 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 17 09:28:24 chocopi volumio[874]: info: Enabling MyMusic plugin upnp Jan 17 09:28:24 chocopi volumio[874]: info: Enabling plugin upnp Jan 17 09:28:24 chocopi volumio[874]: info: Loading plugin "upnp"... Jan 17 09:28:24 chocopi volumio[874]: info: [1737102504375] Starting Upmpd Daemon Jan 17 09:28:24 chocopi volumio[874]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 17 09:28:24 chocopi volumio[874]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 17 09:28:24 chocopi volumio[874]: Error: listen EADDRINUSE: address already in use :::6599 Jan 17 09:28:24 chocopi volumio[874]: at Server.setupListenHandle [as _listen2] (net.js:1318:16) Jan 17 09:28:24 chocopi volumio[874]: at listenInCluster (net.js:1366:12) Jan 17 09:28:24 chocopi volumio[874]: at Server.listen (net.js:1452:7) Jan 17 09:28:24 chocopi volumio[874]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Jan 17 09:28:24 chocopi volumio[874]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Jan 17 09:28:24 chocopi volumio[874]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Jan 17 09:28:24 chocopi volumio[874]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jan 17 09:28:24 chocopi volumio[874]: at processTicksAndRejections (internal/process/task_queues.js:75:11) { Jan 17 09:28:24 chocopi volumio[874]: code: 'EADDRINUSE', Jan 17 09:28:24 chocopi volumio[874]: errno: -98, Jan 17 09:28:24 chocopi volumio[874]: syscall: 'listen', Jan 17 09:28:24 chocopi volumio[874]: address: '::', Jan 17 09:28:24 chocopi volumio[874]: port: 6599 Jan 17 09:28:24 chocopi volumio[874]: } Jan 17 09:28:24 chocopi volumio[874]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 17 09:28:24 chocopi sudo[4923]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-17 09:27 Jan 17 09:28:24 chocopi sudo[4923]: 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="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"