-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Mon 2025-02-24 16:10:11 CET. -- Feb 24 16:09:07 volumio systemd-timedated[1090]: Changed local time to Mon Feb 24 16:09:07 2025 Feb 24 16:09:07 volumio sudo[1088]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:07 volumio volumio-time-update[686]: volumio-time-update-util: System time updated successfully. Feb 24 16:09:07 volumio systemd[1]: Started Volumio Time Update Utility. Feb 24 16:09:07 volumio volumio[1066]: info: ------------------------------------------- Feb 24 16:09:07 volumio volumio[1066]: info: ----- Volumio3 ---- Feb 24 16:09:07 volumio volumio[1066]: info: ------------------------------------------- Feb 24 16:09:07 volumio volumio[1066]: info: ----- System startup ---- Feb 24 16:09:07 volumio volumio[1066]: info: ------------------------------------------- Feb 24 16:09:07 volumio nmbd[823]: [2025/02/24 16:09:07.705527, 0] ../lib/util/become_daemon.c:138(daemon_ready) Feb 24 16:09:07 volumio systemd[1]: Started Samba NMB Daemon. Feb 24 16:09:07 volumio volumio[1066]: info: MYVOLUMIO Environment detected Feb 24 16:09:07 volumio nmbd[823]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Feb 24 16:09:07 volumio systemd[1]: Starting Samba Winbind Daemon... Feb 24 16:09:07 volumio volumio[1066]: info: Plugin folders cleanup Feb 24 16:09:07 volumio volumio[1066]: info: Scanning into folder /volumio/app/plugins/ Feb 24 16:09:07 volumio volumio[1066]: info: Scanning category audio_interface Feb 24 16:09:07 volumio volumio[1066]: info: Scanning category miscellanea Feb 24 16:09:07 volumio volumio[1066]: info: Scanning category music_service Feb 24 16:09:07 volumio volumio[1066]: info: Scanning category plugins.json Feb 24 16:09:07 volumio volumio[1066]: info: Scanning category system_controller Feb 24 16:09:07 volumio volumio[1066]: info: Scanning category user_interface Feb 24 16:09:07 volumio volumio[1066]: info: Scanning into folder /data/plugins/ Feb 24 16:09:07 volumio volumio[1066]: info: Scanning category audio_interface Feb 24 16:09:07 volumio volumio[1066]: info: Scanning category music_service Feb 24 16:09:07 volumio volumio[1066]: info: Scanning category system_controller Feb 24 16:09:07 volumio volumio[1066]: info: Scanning category user_interface Feb 24 16:09:07 volumio volumio[1066]: info: Plugin folders cleanup completed Feb 24 16:09:07 volumio volumio[1066]: info: ------------------------------------------- Feb 24 16:09:07 volumio volumio[1066]: info: ----- Core plugins startup ---- Feb 24 16:09:07 volumio volumio[1066]: info: ------------------------------------------- Feb 24 16:09:07 volumio volumio[1066]: info: Loading plugins from folder /volumio/app/plugins/ Feb 24 16:09:07 volumio volumio[1066]: info: Adding plugin upnp to MyMusic Plugins Feb 24 16:09:07 volumio volumio[1066]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 24 16:09:07 volumio volumio[1066]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 24 16:09:07 volumio volumio[1066]: info: Loading plugins from folder /data/plugins/ Feb 24 16:09:07 volumio volumio[1066]: info: Loading plugin "system"... Feb 24 16:09:07 volumio volumio[1066]: info: Loading plugin "ampswitch"... Feb 24 16:09:08 volumio winbindd[1100]: [2025/02/24 16:09:08.009160, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Feb 24 16:09:08 volumio winbindd[1100]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Feb 24 16:09:08 volumio winbindd[1100]: [2025/02/24 16:09:08.024599, 0] ../lib/util/become_daemon.c:138(daemon_ready) Feb 24 16:09:08 volumio winbindd[1100]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Feb 24 16:09:08 volumio systemd[1]: Started Samba Winbind Daemon. Feb 24 16:09:08 volumio systemd[1]: Starting Samba SMB Daemon... Feb 24 16:09:08 volumio volumio[1066]: info: Applying required configuration parameters for plugin ampswitch Feb 24 16:09:08 volumio volumio[1066]: info: Loading plugin "appearance"... Feb 24 16:09:08 volumio winbindd[1100]: [2025/02/24 16:09:08.387728, 0] ../source3/winbindd/wb_lookupsids.c:659(wb_lookupsids_recv) Feb 24 16:09:08 volumio winbindd[1100]: res_names->count = 3, expected 4 Feb 24 16:09:08 volumio smbd[1110]: [2025/02/24 16:09:08.405614, 0] ../lib/util/become_daemon.c:138(daemon_ready) Feb 24 16:09:08 volumio smbd[1110]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Feb 24 16:09:08 volumio systemd[1]: Started Samba SMB Daemon. Feb 24 16:09:08 volumio systemd[1]: Reached target Multi-User System. Feb 24 16:09:08 volumio systemd[1]: Reached target Graphical Interface. Feb 24 16:09:08 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Feb 24 16:09:08 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Feb 24 16:09:08 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Feb 24 16:09:08 volumio systemd[1]: Startup finished in 11.922s (kernel) + 21.408s (userspace) = 33.330s. Feb 24 16:09:09 volumio volumio[1066]: info: Loading plugin "network"... Feb 24 16:09:09 volumio volumio[1066]: info: Refreshing Cached IP Addresses Feb 24 16:09:09 volumio sudo[1121]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 24 16:09:09 volumio sudo[1121]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:09 volumio sudo[1121]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:09 volumio sudo[1123]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 24 16:09:09 volumio sudo[1123]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:09 volumio sudo[1123]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:09 volumio volumio[1066]: info: Loading plugin "services"... Feb 24 16:09:09 volumio volumio[1066]: info: Loading plugin "alsa_controller"... Feb 24 16:09:09 volumio sudo[1132]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 24 16:09:09 volumio sudo[1132]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:09 volumio volumio[1066]: warn: Unable to locate the audio output device IQaudIO DAC Plus. Please configure a valid output device. Feb 24 16:09:09 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 24 16:09:09 volumio volumio[1066]: info: Loading plugin "wizard"... Feb 24 16:09:09 volumio volumio[1066]: info: Loading plugin "networkfs"... Feb 24 16:09:09 volumio volumio[1066]: info: Starting Udev Watcher for removable devices Feb 24 16:09:09 volumio volumio[1066]: info: Ignoring mount for partition: boot Feb 24 16:09:09 volumio volumio[1066]: info: Ignoring mount for partition: volumio Feb 24 16:09:09 volumio volumio[1066]: info: Ignoring mount for partition: volumio_data Feb 24 16:09:09 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 24 16:09:09 volumio volumio[1066]: info: Loading plugin "volumio_command_line_client"... Feb 24 16:09:09 volumio volumio[1066]: info: Loading plugin "upnp"... Feb 24 16:09:09 volumio volumio[1066]: info: [1740409749460] Starting Upmpd Daemon Feb 24 16:09:09 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 24 16:09:09 volumio volumio[1066]: info: Loading plugin "my_music"... Feb 24 16:09:09 volumio volumio[1066]: info: Loading plugin "mpd"... Feb 24 16:09:09 volumio volumio[1066]: info: Loading plugin "upnp_browser"... Feb 24 16:09:10 volumio volumio[1066]: info: Loading plugin "alarm-clock"... Feb 24 16:09:10 volumio volumio[1066]: info: Loading plugin "airplay_emulation"... Feb 24 16:09:10 volumio volumio[1066]: info: Starting Shairport Sync Feb 24 16:09:10 volumio volumio[1066]: info: Loading plugin "last_100"... Feb 24 16:09:10 volumio volumio[1066]: info: Loading plugin "webradio"... Feb 24 16:09:10 volumio volumio[1066]: info: Loading plugin "i2s_dacs"... Feb 24 16:09:10 volumio volumio[1066]: info: Loading plugin "volumiodiscovery"... Feb 24 16:09:10 volumio volumio[1066]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 24 16:09:10 volumio volumio[1066]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 24 16:09:10 volumio volumio[1066]: *** WARNING *** For more information see Feb 24 16:09:10 volumio node[1066]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 24 16:09:10 volumio volumio[1066]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 24 16:09:10 volumio volumio[1066]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 24 16:09:10 volumio volumio[1066]: *** WARNING *** For more information see Feb 24 16:09:10 volumio node[1066]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 24 16:09:10 volumio node[1066]: *** WARNING *** For more information see Feb 24 16:09:10 volumio node[1066]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 24 16:09:10 volumio node[1066]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 24 16:09:10 volumio node[1066]: *** WARNING *** For more information see Feb 24 16:09:10 volumio volumio[1066]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 24 16:09:10 volumio volumio[1066]: info: Discovery: Started advertising with name: Volumio Feb 24 16:09:10 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 24 16:09:10 volumio volumio[1066]: info: Loading plugin "bandcamp"... Feb 24 16:09:10 volumio sudo[1132]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:11 volumio volumio[1066]: info: Loading plugin "calmradio"... Feb 24 16:09:11 volumio volumio[1066]: info: Loading plugin "soundcloud"... Feb 24 16:09:12 volumio volumio[1066]: info: Loading plugin "spop"... Feb 24 16:09:13 volumio volumio[1066]: info: Loading plugin "youtube2"... Feb 24 16:09:13 volumio volumio-remote-updater[687]: [2025-02-24 16:09:13] [connect] Successful connection Feb 24 16:09:15 volumio volumio[1066]: info: Loading plugin "autostart"... Feb 24 16:09:15 volumio volumio[1066]: info: Applying required configuration parameters for plugin autostart Feb 24 16:09:15 volumio volumio[1066]: info: AutoStart - onVolumioStart - read config.json Feb 24 16:09:15 volumio volumio[1066]: info: Loading plugin "outputs"... Feb 24 16:09:15 volumio volumio[1066]: info: Loading plugin "albumart"... Feb 24 16:09:15 volumio volumio[1066]: info: Plugin example_plugin is not enabled Feb 24 16:09:15 volumio volumio[1066]: info: Loading plugin "inputs"... Feb 24 16:09:15 volumio volumio[1066]: info: Loading plugin "updater_comm"... Feb 24 16:09:15 volumio volumio[1066]: info: Plugin mpdemulation is not enabled Feb 24 16:09:15 volumio volumio[1066]: info: Loading plugin "rest_api"... Feb 24 16:09:15 volumio volumio[1066]: info: Loading plugin "websocket"... Feb 24 16:09:15 volumio volumio[1066]: info: Starting Socket.io Server version 2.3.0 Feb 24 16:09:15 volumio volumio[1066]: info: Loading plugin "fusiondsp"... Feb 24 16:09:15 volumio volumio[1066]: Forking 3 albumart workers Feb 24 16:09:16 volumio volumio[1066]: info: Loading plugin "mpdoutput"... Feb 24 16:09:16 volumio volumio[1066]: info: Loading plugin "80s80s"... Feb 24 16:09:16 volumio volumio[1066]: Starting albumart workers Feb 24 16:09:16 volumio volumio[1066]: Starting albumart workers Feb 24 16:09:16 volumio volumio[1066]: Starting albumart workers Feb 24 16:09:16 volumio volumio[1066]: info: Applying required configuration parameters for plugin 80s80s Feb 24 16:09:16 volumio volumio[1066]: info: [1740409756588] [80s80s] API delay: 30 Feb 24 16:09:16 volumio volumio[1066]: info: Loading plugin "RoonBridge"... Feb 24 16:09:16 volumio volumio[1066]: info: Applying required configuration parameters for plugin RoonBridge Feb 24 16:09:16 volumio volumio[1066]: info: Loading plugin "controradio"... Feb 24 16:09:16 volumio volumio[1066]: error: !!!! WARNING !!!! Feb 24 16:09:16 volumio volumio[1066]: error: The plugin music_service/controradio failed to load, setting it to stopped. Error: Error: Cannot find module 'fast-xml-parser' Feb 24 16:09:16 volumio volumio[1066]: Require stack: Feb 24 16:09:16 volumio volumio[1066]: - /data/plugins/music_service/controradio/index.js Feb 24 16:09:16 volumio volumio[1066]: - /volumio/app/pluginmanager.js Feb 24 16:09:16 volumio volumio[1066]: - /volumio/app/index.js Feb 24 16:09:16 volumio volumio[1066]: - /volumio/index.js Feb 24 16:09:16 volumio volumio[1066]: error: Stack trace: Error: Cannot find module 'fast-xml-parser' Feb 24 16:09:16 volumio volumio[1066]: Require stack: Feb 24 16:09:16 volumio volumio[1066]: - /data/plugins/music_service/controradio/index.js Feb 24 16:09:16 volumio volumio[1066]: - /volumio/app/pluginmanager.js Feb 24 16:09:16 volumio volumio[1066]: - /volumio/app/index.js Feb 24 16:09:16 volumio volumio[1066]: - /volumio/index.js Feb 24 16:09:16 volumio volumio[1066]: at Function.Module._resolveFilename (internal/modules/cjs/loader.js:880:15) Feb 24 16:09:16 volumio volumio[1066]: at Function.Module._load (internal/modules/cjs/loader.js:725:27) Feb 24 16:09:16 volumio volumio[1066]: at Module.require (internal/modules/cjs/loader.js:952:19) Feb 24 16:09:16 volumio volumio[1066]: at require (internal/modules/cjs/helpers.js:88:18) Feb 24 16:09:16 volumio volumio[1066]: at Object. (/data/plugins/music_service/controradio/index.js:5:21) Feb 24 16:09:16 volumio volumio[1066]: at Module._compile (internal/modules/cjs/loader.js:1063:30) Feb 24 16:09:16 volumio volumio[1066]: at Object.Module._extensions..js (internal/modules/cjs/loader.js:1092:10) Feb 24 16:09:16 volumio volumio[1066]: at Module.load (internal/modules/cjs/loader.js:928:32) Feb 24 16:09:16 volumio volumio[1066]: at Function.Module._load (internal/modules/cjs/loader.js:769:14) Feb 24 16:09:16 volumio volumio[1066]: at Module.require (internal/modules/cjs/loader.js:952:19) Feb 24 16:09:16 volumio volumio[1066]: at require (internal/modules/cjs/helpers.js:88:18) Feb 24 16:09:16 volumio volumio[1066]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:235:29) Feb 24 16:09:16 volumio volumio[1066]: at /volumio/app/pluginmanager.js:338:34 Feb 24 16:09:16 volumio volumio[1066]: at Array.forEach () Feb 24 16:09:16 volumio volumio[1066]: at HashMap. (/volumio/app/pluginmanager.js:337:20) Feb 24 16:09:16 volumio volumio[1066]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Feb 24 16:09:16 volumio volumio[1066]: error: !!!! WARNING !!!! Feb 24 16:09:16 volumio volumio[1066]: info: Loading plugin "dmd2_music"... Feb 24 16:09:17 volumio volumio[1066]: info: Loading plugin "lms"... Feb 24 16:09:17 volumio volumio[1066]: info: Loading plugin "personal_radio"... Feb 24 16:09:18 volumio volumio[1066]: info: ControllerPersonalRadio::constructor Feb 24 16:09:18 volumio volumio[1066]: info: Loading plugin "touch_display"... Feb 24 16:09:18 volumio volumio[1066]: info: Applying required configuration parameters for plugin touch_display Feb 24 16:09:18 volumio volumio[1066]: info: Loading i18n strings for locale pl Feb 24 16:09:18 volumio volumio[1066]: info: Plugin mpdoutput has duplicated i18n key SAVE. It is ignored. Feb 24 16:09:18 volumio volumio[1066]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Feb 24 16:09:18 volumio volumio[1066]: Updating browse sources language Feb 24 16:09:18 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 24 16:09:18 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 16:09:18 volumio volumio[1066]: info: CoreCommandRouter::initPlayerControls Feb 24 16:09:18 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:18 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:18 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:18 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:18 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:18 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:18 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 16:09:18 volumio volumio[1066]: Express server listening on port 3000 Feb 24 16:09:18 volumio volumio[1066]: [Metrics] WebUI: 12s 409.32ms Feb 24 16:09:18 volumio volumio[1066]: info: CoreStateMachine::resetVolumioState Feb 24 16:09:18 volumio volumio[1066]: info: CoreStateMachine::getcurrentVolume Feb 24 16:09:18 volumio volumio[1066]: info: CoreCommandRouter::volumioRetrievevolume Feb 24 16:09:18 volumio volumio[1066]: info: CoreStateMachine::pushState Feb 24 16:09:18 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:18 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 16:09:18 volumio volumio[1066]: info: CoreCommandRouter::volumioPushState Feb 24 16:09:18 volumio volumio[1066]: info: Volumio Network Manager: Network status updated: 2 Feb 24 16:09:18 volumio volumio[1066]: verbose: New Socket.io Connection to 192.168.8.168 from 192.168.8.156 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/133.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Feb 24 16:09:19 volumio volumio[1066]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 24 16:09:19 volumio volumio[1066]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 16:09:19 volumio volumio[1066]: info: Executing start script for DAC IQaudIO DAC Plus Feb 24 16:09:19 volumio volumio[1066]: info: Reloading queue from file Feb 24 16:09:19 volumio volumio[1066]: info: CoreStateMachine::setRepeat null single undefined Feb 24 16:09:19 volumio volumio[1066]: info: CoreStateMachine::pushState Feb 24 16:09:19 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::volumioPushState Feb 24 16:09:19 volumio volumio[1066]: info: CoreStateMachine::setRandom null Feb 24 16:09:19 volumio volumio[1066]: info: CoreStateMachine::pushState Feb 24 16:09:19 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::volumioPushState Feb 24 16:09:19 volumio volumio[1066]: info: Setting Device type: Raspberry PI Feb 24 16:09:19 volumio volumio[1066]: info: DAC script executed Feb 24 16:09:19 volumio volumio[1066]: info: Completed loading Core Plugins Feb 24 16:09:19 volumio volumio[1066]: info: Preparing to generate the ALSA configuration file Feb 24 16:09:19 volumio volumio[1066]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Feb 24 16:09:19 volumio volumio[1066]: info: USB Boot Capable - System SBC Revision found in cpuinfo: d03115 Feb 24 16:09:19 volumio volumio[1066]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Feb 24 16:09:19 volumio volumio[1066]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Feb 24 16:09:19 volumio volumio[1066]: info: Reading ALSA contributions from plugins. Feb 24 16:09:19 volumio volumio[1066]: info: Asound.conf file unchanged, so no further update is needed Feb 24 16:09:19 volumio volumio[1066]: info: Output device has changed, restarting MPD Feb 24 16:09:19 volumio sudo[1216]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 24 16:09:19 volumio volumio[1066]: info: Output device has changed, restarting Shairport Sync Feb 24 16:09:19 volumio sudo[1216]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 16:09:19 volumio sudo[1216]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:19 volumio sudo[1218]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 24 16:09:19 volumio sudo[1218]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:19 volumio systemd[1]: Stopping Music Player Daemon... Feb 24 16:09:19 volumio volumio[1066]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 24 16:09:19 volumio volumio[1066]: info: ___________ START PLUGINS ___________ Feb 24 16:09:19 volumio volumio[1066]: info: ControllerMpd::onStart: Initializing MPD Feb 24 16:09:19 volumio volumio[1066]: info: Creating MPD Configuration file Feb 24 16:09:19 volumio systemd[1]: mpd.service: Succeeded. Feb 24 16:09:19 volumio systemd[1]: Stopped Music Player Daemon. Feb 24 16:09:19 volumio sudo[1246]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 24 16:09:19 volumio sudo[1246]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 24 16:09:19 volumio volumio[1066]: info: [1740409759393] CoreMusicLibrary::Adding element Serwery Mediów Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 16:09:19 volumio sudo[1246]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:19 volumio systemd[1]: Starting Music Player Daemon... Feb 24 16:09:19 volumio sudo[1253]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 24 16:09:19 volumio sudo[1253]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:19 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Feb 24 16:09:19 volumio systemd[1]: mpd.service: Succeeded. Feb 24 16:09:19 volumio systemd[1]: Stopped Music Player Daemon. Feb 24 16:09:19 volumio systemd[1]: Starting Music Player Daemon... Feb 24 16:09:19 volumio volumio[1066]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 16:09:19 volumio sudo[1258]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 24 16:09:19 volumio sudo[1258]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:19 volumio volumio[1066]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 24 16:09:19 volumio volumio[1066]: info: [1740409759497] CoreMusicLibrary::Adding element Last_100 Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 24 16:09:19 volumio sudo[1258]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 24 16:09:19 volumio volumio[1066]: info: [1740409759499] CoreMusicLibrary::Adding element Webradio Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 24 16:09:19 volumio volumio[1066]: info: Initializing BBC Radios Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 24 16:09:19 volumio volumio[1066]: info: [1740409759574] CoreMusicLibrary::Adding element Bandcamp Discover Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 24 16:09:19 volumio volumio[1066]: Cannot find translation for source Bandcamp Discover Feb 24 16:09:19 volumio volumio[1066]: info: Adding Calm Radio to Browse Sources Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 24 16:09:19 volumio volumio[1066]: info: [1740409759578] CoreMusicLibrary::Adding element Calm Radio Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 24 16:09:19 volumio volumio[1066]: Cannot find translation for source Bandcamp Discover Feb 24 16:09:19 volumio volumio[1066]: Cannot find translation for source Calm Radio Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 24 16:09:19 volumio volumio[1066]: info: [1740409759586] CoreMusicLibrary::Adding element SoundCloud Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 24 16:09:19 volumio volumio[1066]: Cannot find translation for source Bandcamp Discover Feb 24 16:09:19 volumio volumio[1066]: Cannot find translation for source Calm Radio Feb 24 16:09:19 volumio volumio[1066]: Cannot find translation for source SoundCloud Feb 24 16:09:19 volumio volumio[1066]: info: Creating Spotify config file Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 24 16:09:19 volumio volumio[1066]: info: [1740409759655] CoreMusicLibrary::Adding element YouTube2 Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 24 16:09:19 volumio volumio[1066]: Cannot find translation for source Bandcamp Discover Feb 24 16:09:19 volumio volumio[1066]: Cannot find translation for source Calm Radio Feb 24 16:09:19 volumio volumio[1066]: Cannot find translation for source SoundCloud Feb 24 16:09:19 volumio volumio[1066]: Cannot find translation for source YouTube2 Feb 24 16:09:19 volumio volumio[1066]: info: AutoStart - onStart Feb 24 16:09:19 volumio volumio[1066]: info: Loading i18n strings for locale pl Feb 24 16:09:19 volumio volumio[1066]: info: Plugin mpdoutput has duplicated i18n key SAVE. It is ignored. Feb 24 16:09:19 volumio volumio[1066]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:19 volumio volumio[1066]: info: FusionDsp - mixtype--------------------- None Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 24 16:09:19 volumio volumio[1066]: info: [1740409759679] CoreMusicLibrary::Adding element 80s80s Radio Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 24 16:09:19 volumio volumio[1066]: Cannot find translation for source Bandcamp Discover Feb 24 16:09:19 volumio volumio[1066]: Cannot find translation for source Calm Radio Feb 24 16:09:19 volumio volumio[1066]: Cannot find translation for source SoundCloud Feb 24 16:09:19 volumio volumio[1066]: Cannot find translation for source YouTube2 Feb 24 16:09:19 volumio volumio[1066]: Cannot find translation for source 80s80s Radio Feb 24 16:09:19 volumio volumio[1066]: info: Stopping AccessToken refresher cron for DMD2 Music Feb 24 16:09:19 volumio sudo[1277]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 24 16:09:19 volumio sudo[1277]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:19 volumio volumio[1066]: info: AccessToken refresher cron started for DMD2 Music Feb 24 16:09:19 volumio sudo[1281]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart logitechmediaserver Feb 24 16:09:19 volumio sudo[1281]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 24 16:09:19 volumio volumio[1066]: info: [1740409759802] CoreMusicLibrary::Adding element Personal Radio Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 24 16:09:19 volumio volumio[1066]: Cannot find translation for source Bandcamp Discover Feb 24 16:09:19 volumio volumio[1066]: Cannot find translation for source Calm Radio Feb 24 16:09:19 volumio volumio[1066]: Cannot find translation for source SoundCloud Feb 24 16:09:19 volumio volumio[1066]: Cannot find translation for source YouTube2 Feb 24 16:09:19 volumio volumio[1066]: Cannot find translation for source 80s80s Radio Feb 24 16:09:19 volumio volumio[1066]: Cannot find translation for source Personal Radio Feb 24 16:09:19 volumio systemd[1]: Started RoonBridge. Feb 24 16:09:19 volumio volumio[1066]: info: Loading i18n strings for locale pl Feb 24 16:09:19 volumio volumio[1066]: info: Plugin mpdoutput has duplicated i18n key SAVE. It is ignored. Feb 24 16:09:19 volumio volumio[1066]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Feb 24 16:09:19 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 24 16:09:19 volumio volumio[1066]: info: Volumio Calling Home Feb 24 16:09:19 volumio sudo[1277]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:19 volumio systemd[1]: /data/plugins/music_service/lms/unit/logitechmediaserver.service:7: PIDFile= references path below legacy directory /var/run/, updating /var/run/logitechmediaserver.pid → /run/logitechmediaserver.pid; please update the unit file accordingly. Feb 24 16:09:19 volumio systemd[1]: Starting Logitech Media Server Daemon... Feb 24 16:09:19 volumio systemd[1]: Started Logitech Media Server Daemon. Feb 24 16:09:19 volumio sudo[1281]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:19 volumio systemd[1294]: logitechmediaserver.service: Failed to execute command: No such file or directory Feb 24 16:09:19 volumio systemd[1294]: logitechmediaserver.service: Failed at step EXEC spawning /usr/sbin/squeezeboxserver: No such file or directory Feb 24 16:09:19 volumio systemd[1]: logitechmediaserver.service: Main process exited, code=exited, status=203/EXEC Feb 24 16:09:19 volumio systemd[1]: logitechmediaserver.service: Failed with result 'exit-code'. Feb 24 16:09:19 volumio volumio[1066]: info: Preparing to generate the ALSA configuration file Feb 24 16:09:19 volumio sudo[1297]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Feb 24 16:09:19 volumio sudo[1297]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:20 volumio sudo[1299]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Feb 24 16:09:20 volumio sudo[1299]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:20 volumio sudo[1297]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:20 volumio sudo[1304]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Feb 24 16:09:20 volumio sudo[1304]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:20 volumio systemd[1]: Reloading. Feb 24 16:09:20 volumio sudo[1307]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 24 16:09:20 volumio sudo[1307]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:20 volumio sudo[1307]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:20 volumio volumio[1066]: info: Discovery: adding 05e92c2e-b18c-4697-8071-16dc967ef248 Feb 24 16:09:20 volumio volumio[1066]: info: Discovery: Found device Volumio Feb 24 16:09:20 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:20 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:20 volumio sudo[1309]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 24 16:09:20 volumio sudo[1309]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:20 volumio volumio[1066]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Feb 24 16:09:20 volumio volumio[1066]: info: Reading ALSA contributions from plugins. Feb 24 16:09:20 volumio volumio[1066]: info: touch_display: Backlight interface detected. Feb 24 16:09:20 volumio sudo[1309]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:20 volumio volumio[1066]: info: touch_display: systemctl stop getty@tty1.service succeeded. Feb 24 16:09:20 volumio volumio[1066]: info: logitechmediaserver started Feb 24 16:09:20 volumio volumio[1066]: info: MPD Permissions set Feb 24 16:09:20 volumio volumio[1066]: info: MPD Permissions set Feb 24 16:09:20 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:20 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:20 volumio volumio[1066]: info: Volumio called home Feb 24 16:09:20 volumio volumio[1066]: info: Spotify config file written Feb 24 16:09:20 volumio volumio[1066]: info: [ASDebug] CurState: stop PrevState: na Feb 24 16:09:20 volumio volumio[1066]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Feb 24 16:09:20 volumio volumio[1066]: info: [ASDebug] CurState: stop PrevState: na Feb 24 16:09:20 volumio volumio[1066]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Feb 24 16:09:20 volumio volumio[1066]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Feb 24 16:09:20 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:20 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:20 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:20 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:20 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:20 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:20 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:20 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:20 volumio sudo[1327]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 24 16:09:20 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. Feb 24 16:09:20 volumio sudo[1327]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:20 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 16:09:20 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:20 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:20 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 16:09:20 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:20 volumio volumio[1066]: info: No need to fix Spotify hosts Feb 24 16:09:20 volumio mpd[1265]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 24 16:09:20 volumio mpd[1265]: output: No 'audio_output' defined in config file Feb 24 16:09:20 volumio mpd[1265]: output: Successfully detected a sndio audio device Feb 24 16:09:20 volumio mpd[1265]: zeroconf: No global port, disabling zeroconf Feb 24 16:09:20 volumio systemd[1]: ifup@eth0.service: Current command vanished from the unit file, execution of the command list won't be resumed. Feb 24 16:09:20 volumio volumio[1066]: info: touch_display: No Raspberry Pi Foundation touch screen detected. Feb 24 16:09:20 volumio systemd[1]: /data/plugins/music_service/lms/unit/logitechmediaserver.service:7: PIDFile= references path below legacy directory /var/run/, updating /var/run/logitechmediaserver.pid → /run/logitechmediaserver.pid; please update the unit file accordingly. Feb 24 16:09:20 volumio sudo[1340]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Feb 24 16:09:20 volumio sudo[1340]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:20 volumio sudo[1340]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:20 volumio sudo[1343]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+w /sys/class/backlight/10-0045/brightness Feb 24 16:09:20 volumio sudo[1343]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:20 volumio volumio[1066]: info: Starting Shairport Sync Feb 24 16:09:20 volumio sudo[1343]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:20 volumio sudo[1346]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 24 16:09:20 volumio sudo[1346]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:20 volumio volumio[1066]: info: Starting Shairport Sync Feb 24 16:09:20 volumio sudo[1349]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 24 16:09:20 volumio sudo[1349]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:20 volumio sudo[1352]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 24 16:09:20 volumio sudo[1352]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:20 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:20 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:20 volumio volumio[1066]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Feb 24 16:09:20 volumio systemd[1]: Started Music Player Daemon. Feb 24 16:09:20 volumio sudo[1299]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:20 volumio systemd[1]: systemd-fsckd.service: Succeeded. Feb 24 16:09:20 volumio sudo[1355]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 24 16:09:20 volumio sudo[1253]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:20 volumio sudo[1355]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:20 volumio sudo[1218]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:20 volumio systemd[1]: Reloading. Feb 24 16:09:20 volumio volumio[1066]: info: touch_display: File permissions for backlight brightness control set. Feb 24 16:09:20 volumio volumio[1066]: info: Asound.conf file unchanged, so no further update is needed Feb 24 16:09:20 volumio volumio[1066]: info: Output device has changed, restarting MPD Feb 24 16:09:20 volumio sudo[1363]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 24 16:09:20 volumio sudo[1363]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:20 volumio sudo[1363]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:20 volumio volumio[1066]: info: Output device has changed, restarting Shairport Sync Feb 24 16:09:20 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:20 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 16:09:20 volumio sudo[1369]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 24 16:09:20 volumio sudo[1369]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:21 volumio volumio[1066]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 24 16:09:21 volumio volumio[1066]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 24 16:09:21 volumio volumio[1066]: SPOTIFY: BQDtF3r2W8iqZtTV6NZluU8AW2nl6P6LkI86LWYYG3FUVbciA9HqTFBIc84LKp2D8SAB0lwAQx4ErPhQr_3lAUQQN2mzOYkbvmHQA6N7-o1vl5r6yg8dBJyhG2RLOsEYyeYssNct-600bzbzwPEGsxkiPyPndrGy8HeOnrOdmm1AGS_KMYM8BJUdUGaXI_blkNegd0Uev1zKWFOBeM7w_mDRoN90KPw8mFKwae5aYTrIP_Ki7NhAmhYvdIGTBzq8-8Pb5GpxK4K4wUTBvHUNUF3c5Qa7uSkGc7quQhy_mAY Feb 24 16:09:21 volumio volumio[1066]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 24 16:09:21 volumio volumio[1066]: info: New Spotify access token = BQDtF3r2W8iqZtTV6NZluU8AW2nl6P6LkI86LWYYG3FUVbciA9HqTFBIc84LKp2D8SAB0lwAQx4ErPhQr_3lAUQQN2mzOYkbvmHQA6N7-o1vl5r6yg8dBJyhG2RLOsEYyeYssNct-600bzbzwPEGsxkiPyPndrGy8HeOnrOdmm1AGS_KMYM8BJUdUGaXI_blkNegd0Uev1zKWFOBeM7w_mDRoN90KPw8mFKwae5aYTrIP_Ki7NhAmhYvdIGTBzq8-8Pb5GpxK4K4wUTBvHUNUF3c5Qa7uSkGc7quQhy_mAY Feb 24 16:09:21 volumio volumio[1066]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 24 16:09:21 volumio kernel: ws_touchscreen 10-0045: I2C write failed: -5 Feb 24 16:09:21 volumio kernel: ws_touchscreen 10-0045: I2C write failed: -5 Feb 24 16:09:21 volumio volumio[1066]: info: touch_display: systemctl disable getty@tty1.service succeeded. Feb 24 16:09:21 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. Feb 24 16:09:21 volumio volumio[1066]: info: [ASDebug] Togle GPIO: OFF Feb 24 16:09:21 volumio volumio[1066]: (node:1066) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead. Feb 24 16:09:21 volumio volumio[1066]: (Use `node --trace-deprecation ...` to show where the warning was created) Feb 24 16:09:21 volumio volumio[1066]: (node:1066) [DEP0106] DeprecationWarning: crypto.createDecipher is deprecated. Feb 24 16:09:21 volumio RoonBridge[1279]: 00:00:00.011 Warn: get lock file path: /tmp/.rnbgem0- Feb 24 16:09:21 volumio volumio[1066]: info: MPD Permissions set Feb 24 16:09:21 volumio volumio[1066]: error: MPD error: The expression evaluated to a falsy value: Feb 24 16:09:21 volumio volumio[1066]: assert.ok(self.idling) Feb 24 16:09:21 volumio volumio[1066]: error: The expression evaluated to a falsy value: Feb 24 16:09:21 volumio volumio[1066]: assert.ok(self.idling) Feb 24 16:09:21 volumio volumio[1066]: info: MPD running with PID1265 Feb 24 16:09:21 volumio volumio[1066]: ,establishing connection Feb 24 16:09:21 volumio volumio[1066]: error: updateQueue error: null Feb 24 16:09:21 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:21 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:21 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:21 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:21 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:21 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:21 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:21 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:21 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 16:09:21 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:21 volumio volumio[1066]: error: updateQueue error: null Feb 24 16:09:21 volumio volumio[1066]: info: Starting Shairport Sync Feb 24 16:09:21 volumio sh[617]: timed out Feb 24 16:09:21 volumio dhcpcd[661]: timed out Feb 24 16:09:21 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:21 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:21 volumio volumio[1066]: info: CoreCommandRouter::volumioPause Feb 24 16:09:21 volumio volumio[1066]: info: CoreStateMachine::pause Feb 24 16:09:21 volumio volumio[1066]: info: mpdhttpout --- Volumio set on pause Feb 24 16:09:21 volumio volumio[1066]: info: mpdhttpout ---Configuration successfully added to mpd.conf. Feb 24 16:09:21 volumio systemd[1]: /data/plugins/music_service/lms/unit/logitechmediaserver.service:7: PIDFile= references path below legacy directory /var/run/, updating /var/run/logitechmediaserver.pid → /run/logitechmediaserver.pid; please update the unit file accordingly. Feb 24 16:09:21 volumio sh[617]: dhcpcd exited Feb 24 16:09:21 volumio dhcpcd[661]: dhcpcd exited Feb 24 16:09:21 volumio sudo[1390]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 24 16:09:21 volumio sudo[1390]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:21 volumio sh[617]: ifup: failed to bring up eth0 Feb 24 16:09:21 volumio sudo[1393]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 24 16:09:21 volumio sudo[1393]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:21 volumio sudo[1393]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:21 volumio sudo[1396]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 24 16:09:21 volumio sudo[1396]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:21 volumio sudo[1396]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:21 volumio volumio[1066]: SPOTIFY: User informations: {"country":"PL","display_name":"Bernard","email":"bmiekisiak+spotify1@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31bsbacslhkjbigewxyd52xej2hq"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31bsbacslhkjbigewxyd52xej2hq","id":"31bsbacslhkjbigewxyd52xej2hq","images":[],"product":"premium","type":"user","uri":"spotify:user:31bsbacslhkjbigewxyd52xej2hq"} Feb 24 16:09:21 volumio volumio[1066]: info: Spotify Successfully logged in Feb 24 16:09:21 volumio volumio[1066]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 24 16:09:21 volumio volumio[1066]: info: [1740409761376] CoreMusicLibrary::Adding element Spotify Feb 24 16:09:21 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 24 16:09:21 volumio volumio[1066]: Cannot find translation for source Bandcamp Discover Feb 24 16:09:21 volumio volumio[1066]: Cannot find translation for source Calm Radio Feb 24 16:09:21 volumio volumio[1066]: Cannot find translation for source SoundCloud Feb 24 16:09:21 volumio volumio[1066]: Cannot find translation for source YouTube2 Feb 24 16:09:21 volumio volumio[1066]: Cannot find translation for source 80s80s Radio Feb 24 16:09:21 volumio volumio[1066]: Cannot find translation for source Personal Radio Feb 24 16:09:21 volumio volumio[1066]: Cannot find translation for source Spotify Feb 24 16:09:21 volumio volumio[1066]: verbose: New Socket.io Connection to 192.168.8.168 from 192.168.8.156 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/133.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Feb 24 16:09:21 volumio systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Feb 24 16:09:21 volumio systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Feb 24 16:09:21 volumio sudo[1304]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:21 volumio RoonBridge[1279]: 00:00:00.424 Trace: [childprocess] using unix child process Feb 24 16:09:21 volumio volumio[1066]: info: touch_display: systemctl daemon-reload succeeded. Feb 24 16:09:21 volumio sudo[1399]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Feb 24 16:09:21 volumio sudo[1399]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:21 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 24 16:09:21 volumio systemd[1]: Stopping Music Player Daemon... Feb 24 16:09:21 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Feb 24 16:09:21 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 24 16:09:21 volumio sudo[1355]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:21 volumio systemd[1]: Started go-librespot Daemon. Feb 24 16:09:21 volumio sudo[1327]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:21 volumio go-librespot[1403]: go-librespot daemon starting... Feb 24 16:09:21 volumio RoonBridge[1279]: 00:00:00.523 Debug: PathForResource, filename: ../.update Feb 24 16:09:21 volumio systemd[1]: shairport-sync.service: Succeeded. Feb 24 16:09:21 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 24 16:09:21 volumio systemd[1]: mpd.service: Succeeded. Feb 24 16:09:21 volumio systemd[1]: Stopped Music Player Daemon. Feb 24 16:09:21 volumio volumio[1066]: info: Upmpdcli Daemon Started Feb 24 16:09:21 volumio sudo[1399]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:21 volumio systemd[1]: Starting Music Player Daemon... Feb 24 16:09:21 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 24 16:09:21 volumio sudo[1346]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:21 volumio sudo[1390]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:21 volumio sudo[1352]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:21 volumio sudo[1349]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:21 volumio sudo[1408]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 24 16:09:21 volumio sudo[1408]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:21 volumio sudo[1408]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:21 volumio sudo[1410]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 24 16:09:21 volumio sudo[1410]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:21 volumio sudo[1410]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:21 volumio volumio[1066]: info: Shairport-Sync Started Feb 24 16:09:21 volumio volumio[1066]: Error adding Membership: Error: addMembership EINVAL Feb 24 16:09:21 volumio volumio[1066]: info: Shairport-Sync Started Feb 24 16:09:21 volumio volumio[1066]: info: Shairport-Sync Started Feb 24 16:09:21 volumio volumio[1066]: error: touch_display: Failed to start volumio-kiosk.service: Error: Command failed: /usr/bin/sudo /bin/systemctl start volumio-kiosk.service Feb 24 16:09:21 volumio volumio[1066]: Failed to start volumio-kiosk.service: Unit volumio-kiosk.service not found. Feb 24 16:09:21 volumio RoonBridge[1279]: 00:00:00.638 Debug: PathForResource, candidate: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/../.update Feb 24 16:09:21 volumio volumio[1066]: info: Completed starting Core Plugins Feb 24 16:09:21 volumio volumio[1066]: info: ------------------------------------------- Feb 24 16:09:21 volumio volumio[1066]: info: ----- MyVolumio plugins startup ---- Feb 24 16:09:21 volumio volumio[1066]: info: ------------------------------------------- Feb 24 16:09:21 volumio volumio[1066]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 24 16:09:21 volumio RoonBridge[1279]: 00:00:00.646 Debug: PathForResource, filename: RAATServer Feb 24 16:09:21 volumio RoonBridge[1279]: 00:00:00.646 Debug: PathForResource, candidate: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RAATServer Feb 24 16:09:21 volumio RoonBridge[1279]: 00:00:00.646 Debug: PathForResource, filename: RoonBridgeHelper Feb 24 16:09:21 volumio RoonBridge[1279]: 00:00:00.646 Debug: PathForResource, candidate: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RoonBridgeHelper Feb 24 16:09:21 volumio sudo[1405]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 24 16:09:21 volumio sudo[1405]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:21 volumio sudo[1405]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:21 volumio volumio[1066]: info: Shairport-Sync Started Feb 24 16:09:21 volumio RoonBridge[1279]: Initializing Feb 24 16:09:21 volumio RoonBridge[1279]: 00:00:00.700 Info: Starting /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RoonBridgeHelper Feb 24 16:09:21 volumio RoonBridge[1279]: 00:00:00.749 Info: ConnectOrStartAndWaitForExit RAATServer, path: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RAATServer Feb 24 16:09:21 volumio volumio[1066]: info: camilladsp spawned new process with pid 1433, instance 1, run: true Feb 24 16:09:21 volumio volumio[1066]: info: camilladsp service started and running in background, instance 1 Feb 24 16:09:21 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:21 volumio volumio[1066]: ALSA lib pcm_hw.c:1822:(_snd_pcm_hw_open) Invalid value for card Feb 24 16:09:21 volumio volumio[1066]: cannot open device 'volumioHw': No such device Feb 24 16:09:21 volumio volumio[1066]: error: FusionDsp - ----Hw detection failed :Error: Command failed: /data/plugins/audio_interface/fusiondsp/hw_params volumioHw >/data/configuration/audio_interface/fusiondsp/hwinfo.json Feb 24 16:09:21 volumio volumio[1066]: ALSA lib pcm_hw.c:1822:(_snd_pcm_hw_open) Invalid value for card Feb 24 16:09:21 volumio volumio[1066]: cannot open device 'volumioHw': No such device Feb 24 16:09:21 volumio volumio[1066]: info: FusionDsp loaded Feb 24 16:09:21 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 16:09:21 volumio RoonBridge[1279]: Not Running (.o) Feb 24 16:09:21 volumio volumio[1066]: info: FusionDsp - Reporting Fusion DSP Enabled Feb 24 16:09:21 volumio volumio[1066]: info: Adding Signal Path Element [object Object] Feb 24 16:09:21 volumio volumio[1066]: info: Adding fusiondspeq DSP Signal Path Element Feb 24 16:09:21 volumio volumio[1066]: info: FusionDsp - ---- installed callbackRead Feb 24 16:09:21 volumio sudo[1444]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Feb 24 16:09:21 volumio volumio[1066]: info: FusionDsp - If filter freq >samplerate/2 then disable it Feb 24 16:09:21 volumio sudo[1444]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:21 volumio volumio[1066]: verbose: New Socket.io Connection to 192.168.8.168 from 192.168.8.156 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/133.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Feb 24 16:09:21 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 24 16:09:22 volumio volumio[1066]: error: FusionDsp - WebSocket error: [object Object] Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::volumioGetVisibleSources Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:22 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:22 volumio systemd[1]: Started FusionDsp Daemon. Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 24 16:09:22 volumio sudo[1444]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 24 16:09:22 volumio volumio[1066]: info: Received Get System Info Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 16:09:22 volumio volumio[1066]: info: Discovery: Getting this device information Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:22 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:22 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:22 volumio volumio[1066]: info: Listing playlists Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 24 16:09:22 volumio go-librespot[1403]: time="2025-02-24T16:09:22+01:00" level=info msg="running go-librespot 0.2.0" Feb 24 16:09:22 volumio go-librespot[1403]: time="2025-02-24T16:09:22+01:00" level=debug msg="app state loaded" Feb 24 16:09:22 volumio volumio[1066]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Feb 24 16:09:22 volumio go-librespot[1403]: time="2025-02-24T16:09:22+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 24 16:09:22 volumio volumio[1066]: info: camilladsp spawned new process with pid 1454, instance 1, run: true Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:22 volumio systemd[1]: systemd-hostnamed.service: Succeeded. Feb 24 16:09:22 volumio RoonBridge[1279]: Running Feb 24 16:09:22 volumio volumio[1066]: info: camilladsp spawned new process with pid 1463, instance 1, run: true Feb 24 16:09:22 volumio volumio[1066]: info: camilladsp spawned new process with pid 1477, instance 1, run: true Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:22 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:22 volumio RoonBridge[1279]: 00:00:00.031 Warn: get lock file path: /tmp/.rnbhgem0- Feb 24 16:09:22 volumio volumio[1066]: info: camilladsp spawned new process with pid 1485, instance 1, run: true Feb 24 16:09:22 volumio go-librespot[1403]: time="2025-02-24T16:09:22+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 24 16:09:22 volumio go-librespot[1403]: time="2025-02-24T16:09:22+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 24 16:09:22 volumio go-librespot[1403]: time="2025-02-24T16:09:22+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 24 16:09:22 volumio go-librespot[1403]: time="2025-02-24T16:09:22+01:00" level=info msg="zeroconf server listening on port 42625" Feb 24 16:09:22 volumio volumio[1066]: info: camilladsp spawned new process with pid 1492, instance 1, run: true Feb 24 16:09:22 volumio mpd[1420]: Feb 24 16:09 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 24 16:09:22 volumio systemd[1]: Started Music Player Daemon. Feb 24 16:09:22 volumio volumio[1066]: verbose: New Socket.io Connection to 192.168.8.168 from 192.168.8.156 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/133.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Feb 24 16:09:22 volumio sudo[1369]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:22 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:22 volumio volumio[1066]: info: Received Get System Info Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 16:09:22 volumio volumio[1066]: info: Discovery: Getting this device information Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:22 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:22 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::volumioGetVisibleSources Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:22 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:22 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 24 16:09:22 volumio volumio[1066]: info: Received Get System Info Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 16:09:22 volumio volumio[1066]: info: Discovery: Getting this device information Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:22 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:22 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:22 volumio volumio[1066]: info: Listing playlists Feb 24 16:09:22 volumio volumio[1066]: info: Received Get System Info Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 16:09:22 volumio volumio[1066]: info: Discovery: Getting this device information Feb 24 16:09:22 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:22 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:23 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::volumioGetVisibleSources Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:23 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:23 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 24 16:09:23 volumio volumio[1066]: info: Received Get System Info Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 16:09:23 volumio volumio[1066]: info: Discovery: Getting this device information Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:23 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:23 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:23 volumio volumio[1066]: info: Listing playlists Feb 24 16:09:23 volumio volumio[1066]: info: Received Get System Info Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 16:09:23 volumio volumio[1066]: info: Discovery: Getting this device information Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:23 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:23 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::volumioGetVisibleSources Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:23 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:23 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 24 16:09:23 volumio volumio[1066]: info: Received Get System Info Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 16:09:23 volumio volumio[1066]: info: Discovery: Getting this device information Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:23 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:23 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:23 volumio volumio[1066]: info: Listing playlists Feb 24 16:09:23 volumio volumio[1066]: info: Received Get System Info Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 16:09:23 volumio volumio[1066]: info: Discovery: Getting this device information Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:23 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:23 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:23 volumio go-librespot[1403]: time="2025-02-24T16:09:23+01:00" level=debug msg="obtained new client token: AAC7gFWCvKJFx8WneEvP31/RlCxva1h9PKXM9XvPNrLEFbDDhsqAfFwamqWjexQt2jsz0wQwnmR2lZwnyS6SuXfpTvmcK/P9XcyuN7QfQYIVqihHx+9qnaPw2pIPCrpWf76ohTo/610LiYMmv13jYDDhBOVY4vxoc7Q3Uq54lsW+fivflnXVnN5m9kzKo/7qo0BbzsK/UM20LhaL42Y/V6orOQHDcRdMaMjDxOWu1sKVmafJEeaNT8M=" Feb 24 16:09:23 volumio volumio[1066]: info: camilladsp spawned new process with pid 1505, instance 1, run: true Feb 24 16:09:23 volumio volumio[1066]: error: updateQueue error: null Feb 24 16:09:23 volumio go-librespot[1403]: time="2025-02-24T16:09:23+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 24 16:09:23 volumio volumio[1066]: info: camilladsp spawned new process with pid 1516, instance 1, run: true Feb 24 16:09:23 volumio go-librespot[1403]: time="2025-02-24T16:09:23+01:00" level=debug msg="completed keyexchange" Feb 24 16:09:23 volumio go-librespot[1403]: time="2025-02-24T16:09:23+01:00" level=debug msg="completed challenge" Feb 24 16:09:23 volumio volumio[1401]: Generating RSA private key, 4096 bit long modulus (2 primes) Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio go-librespot[1403]: time="2025-02-24T16:09:23+01:00" level=info msg="authenticated AP as 31bsbacslhkjbigewxyd52xej2hq" Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:23 volumio sudo[1537]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 24 16:09:23 volumio sudo[1537]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:23 volumio systemd[1]: Stopping Music Player Daemon... Feb 24 16:09:23 volumio systemd[1]: mpd.service: Succeeded. Feb 24 16:09:23 volumio systemd[1]: Stopped Music Player Daemon. Feb 24 16:09:23 volumio go-librespot[1403]: time="2025-02-24T16:09:23+01:00" level=info msg="authenticated Login5 as 31bsbacslhkjbigewxyd52xej2hq" Feb 24 16:09:23 volumio go-librespot[1403]: time="2025-02-24T16:09:23+01:00" level=debug msg="initializing zeroconf session, username: 31bsbacslhkjbigewxyd52xej2hq" Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 24 16:09:23 volumio volumio[1066]: info: Received Get System Info Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 16:09:23 volumio volumio[1066]: info: Discovery: Getting this device information Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:23 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 16:09:23 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Feb 24 16:09:23 volumio systemd[1]: Starting Music Player Daemon... Feb 24 16:09:23 volumio volumio[1066]: info: camilladsp spawned new process with pid 1540, instance 1, run: true Feb 24 16:09:23 volumio sudo[1539]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 24 16:09:23 volumio sudo[1539]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:23 volumio sudo[1539]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:24 volumio go-librespot[1403]: time="2025-02-24T16:09:24+01:00" level=debug msg="dealer connection opened" Feb 24 16:09:24 volumio go-librespot[1403]: time="2025-02-24T16:09:24+01:00" level=trace msg="starting accesspoint recv loop" Feb 24 16:09:24 volumio go-librespot[1403]: time="2025-02-24T16:09:24+01:00" level=trace msg="starting dealer recv loop" Feb 24 16:09:24 volumio go-librespot[1403]: time="2025-02-24T16:09:24+01:00" level=trace msg="received accesspoint ping" Feb 24 16:09:24 volumio go-librespot[1403]: time="2025-02-24T16:09:24+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Feb 24 16:09:24 volumio go-librespot[1403]: time="2025-02-24T16:09:24+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Feb 24 16:09:24 volumio go-librespot[1403]: time="2025-02-24T16:09:24+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Feb 24 16:09:24 volumio go-librespot[1403]: time="2025-02-24T16:09:24+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Feb 24 16:09:24 volumio go-librespot[1403]: time="2025-02-24T16:09:24+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Feb 24 16:09:24 volumio go-librespot[1403]: time="2025-02-24T16:09:24+01:00" level=debug msg="received connection id: ZjM3OWY2MmUtY2Y4Mi00MmM0LWJkNDMtYmIyNmUwNDk1YTRmK2RlYWxlcit0Y3A6Ly8wYWNhNWEzNS5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArNzRBNEZCOTFCMzlEMTFFQkQyMjA2MUM0OUNENkE0QzY3MTg2RkQwRDBEMDUzMzY3QUQ5Q0UyODQ5MDc3NDVEOA==" Feb 24 16:09:24 volumio go-librespot[1403]: time="2025-02-24T16:09:24+01:00" level=trace msg="received accesspoint pong ack" Feb 24 16:09:24 volumio go-librespot[1403]: time="2025-02-24T16:09:24+01:00" level=debug msg="put connect state because NEW_DEVICE" Feb 24 16:09:24 volumio go-librespot[1403]: time="2025-02-24T16:09:24+01:00" level=debug msg="update volume to 65535/65535" Feb 24 16:09:25 volumio mpd[1548]: Feb 24 16:09 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 24 16:09:25 volumio systemd[1]: Started Music Player Daemon. Feb 24 16:09:25 volumio sudo[1537]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:25 volumio go-librespot[1403]: time="2025-02-24T16:09:25+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Feb 24 16:09:25 volumio go-librespot[1403]: time="2025-02-24T16:09:25+01:00" level=trace msg="emitting websocket event: volume" Feb 24 16:09:25 volumio volumio[1401]: ........................++++ Feb 24 16:09:28 volumio volumio-remote-updater[687]: [2025-02-24 16:09:28] [connect] Successful connection Feb 24 16:09:29 volumio volumio[1401]: ........................................++++ Feb 24 16:09:29 volumio volumio[1401]: e is 65537 (0x010001) Feb 24 16:09:29 volumio volumio[1401]: writing RSA key Feb 24 16:09:30 volumio volumio[1066]: error: MPD error: Error: This socket has been ended by the other party Feb 24 16:09:30 volumio volumio[1066]: error: This socket has been ended by the other party {"code":"EPIPE"} Feb 24 16:09:30 volumio volumio[1066]: error: MPD error: Error: This socket has been ended by the other party Feb 24 16:09:30 volumio volumio[1066]: error: This socket has been ended by the other party {"code":"EPIPE"} Feb 24 16:09:30 volumio volumio[1066]: error: MPD error: Error: This socket has been ended by the other party Feb 24 16:09:30 volumio volumio[1066]: error: This socket has been ended by the other party {"code":"EPIPE"} Feb 24 16:09:30 volumio volumio[1066]: error: MPD error: Error: This socket has been ended by the other party Feb 24 16:09:30 volumio volumio[1066]: error: This socket has been ended by the other party {"code":"EPIPE"} Feb 24 16:09:30 volumio volumio[1066]: error: MPD error: Error: This socket has been ended by the other party Feb 24 16:09:30 volumio volumio[1066]: error: This socket has been ended by the other party {"code":"EPIPE"} Feb 24 16:09:30 volumio volumio[1066]: error: MPD error: Error: This socket has been ended by the other party Feb 24 16:09:30 volumio volumio[1066]: error: This socket has been ended by the other party {"code":"EPIPE"} Feb 24 16:09:30 volumio volumio[1066]: error: MPD error: Error: This socket has been ended by the other party Feb 24 16:09:30 volumio volumio[1066]: error: This socket has been ended by the other party {"code":"EPIPE"} Feb 24 16:09:30 volumio volumio[1066]: error: MPD error: Error: This socket has been ended by the other party Feb 24 16:09:30 volumio volumio[1066]: error: This socket has been ended by the other party {"code":"EPIPE"} Feb 24 16:09:30 volumio volumio[1066]: error: MPD error: Error: This socket has been ended by the other party Feb 24 16:09:30 volumio volumio[1066]: error: This socket has been ended by the other party {"code":"EPIPE"} Feb 24 16:09:30 volumio volumio[1066]: info: go-librespot daemon successfully initialized Feb 24 16:09:31 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 24 16:09:31 volumio volumio[1066]: info: Received Get System Info Feb 24 16:09:31 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 16:09:31 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 16:09:31 volumio volumio[1066]: info: Discovery: Getting this device information Feb 24 16:09:31 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:31 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:31 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 16:09:31 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Feb 24 16:09:31 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Feb 24 16:09:32 volumio volumio[1066]: info: camilladsp spawned new process with pid 1608, instance 1, run: true Feb 24 16:09:32 volumio volumio-remote-updater[687]: [2025-02-24 16:09:32] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1740409768 101 Feb 24 16:09:32 volumio volumio[1066]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 9 Feb 24 16:09:32 volumio volumio[1066]: error: updateQueue error: null Feb 24 16:09:32 volumio volumio[1066]: info: camilladsp spawned new process with pid 1615, instance 1, run: true Feb 24 16:09:32 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Feb 24 16:09:32 volumio volumio[1066]: info: camilladsp spawned new process with pid 1622, instance 1, run: true Feb 24 16:09:32 volumio volumio[1066]: info: camilladsp spawned new process with pid 1629, instance 1, run: true Feb 24 16:09:32 volumio volumio[1066]: info: camilladsp spawned new process with pid 1636, instance 1, run: true Feb 24 16:09:32 volumio volumio[1066]: info: camilladsp spawned new process with pid 1643, instance 1, run: true Feb 24 16:09:33 volumio volumio[1066]: info: camilladsp spawned new process with pid 1650, instance 1, run: true Feb 24 16:09:33 volumio volumio[1066]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 24 16:09:33 volumio volumio[1066]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 24 16:09:33 volumio volumio[1066]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 24 16:09:33 volumio volumio[1066]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 24 16:09:33 volumio volumio[1066]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 24 16:09:33 volumio volumio[1066]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 24 16:09:33 volumio volumio[1066]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 24 16:09:33 volumio volumio[1066]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 24 16:09:33 volumio volumio[1066]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 24 16:09:33 volumio volumio[1066]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 24 16:09:33 volumio volumio[1066]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 24 16:09:33 volumio volumio[1066]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 24 16:09:33 volumio volumio[1066]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 24 16:09:33 volumio volumio[1066]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 24 16:09:33 volumio volumio[1066]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 24 16:09:33 volumio volumio[1066]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 24 16:09:33 volumio volumio[1066]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 24 16:09:33 volumio volumio[1066]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 24 16:09:33 volumio volumio[1066]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 24 16:09:33 volumio volumio[1066]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 24 16:09:33 volumio volumio[1066]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 24 16:09:33 volumio volumio[1066]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 24 16:09:33 volumio volumio[1066]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 24 16:09:33 volumio volumio[1066]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 24 16:09:33 volumio volumio[1066]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 24 16:09:33 volumio volumio[1066]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 24 16:09:33 volumio volumio[1066]: info: Adding plugin bluetooth to MyMusic Plugins Feb 24 16:09:33 volumio volumio[1066]: info: Adding plugin multiroom to MyMusic Plugins Feb 24 16:09:33 volumio volumio[1066]: info: Adding plugin metavolumio to MyMusic Plugins Feb 24 16:09:33 volumio volumio[1066]: info: Adding plugin cd_controller to MyMusic Plugins Feb 24 16:09:33 volumio volumio[1066]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 24 16:09:33 volumio volumio[1066]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 24 16:09:33 volumio volumio[1066]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 24 16:09:34 volumio volumio[1066]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 24 16:09:34 volumio volumio[1066]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 24 16:09:34 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 16:09:34 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 16:09:34 volumio volumio[1066]: info: Starting MyVolumio Remote Streaming Endpoints Feb 24 16:09:34 volumio volumio[1066]: info: MyVolumio login type: Token Feb 24 16:09:34 volumio volumio[1066]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 24 16:09:34 volumio volumio[1066]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 24 16:09:34 volumio volumio[1066]: info: Starting Streaming Service Transparent Proxy Feb 24 16:09:34 volumio volumio[1066]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 24 16:09:34 volumio volumio[1066]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 24 16:09:34 volumio volumio[1066]: info: Streaming services startup Feb 24 16:09:34 volumio volumio[1066]: info: Starting Streaming Daemon Feb 24 16:09:35 volumio sudo[1666]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 24 16:09:35 volumio sudo[1666]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:35 volumio sudo[1666]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:35 volumio volumio[1066]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 24 16:09:35 volumio volumio[1066]: info: Initializing connection to go-librespot Websocket Feb 24 16:09:35 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 24 16:09:35 volumio volumio[1066]: error: Cannot start Volumio Streaming Daemon Feb 24 16:09:35 volumio volumio[1066]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 24 16:09:35 volumio volumio[1066]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 24 16:09:35 volumio volumio[1066]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 24 16:09:35 volumio go-librespot[1403]: time="2025-02-24T16:09:35+01:00" level=debug msg="new websocket client" Feb 24 16:09:35 volumio volumio[1066]: info: camilladsp spawned new process with pid 1675, instance 1, run: true Feb 24 16:09:35 volumio volumio[1066]: info: Connection to go-librespot Websocket established Feb 24 16:09:35 volumio volumio[1066]: info: camilladsp spawned new process with pid 1682, instance 1, run: true Feb 24 16:09:35 volumio volumio[1066]: info: camilladsp spawned new process with pid 1689, instance 1, run: true Feb 24 16:09:35 volumio volumio[1066]: info: camilladsp spawned new process with pid 1696, instance 1, run: true Feb 24 16:09:35 volumio volumio[1066]: info: camilladsp spawned new process with pid 1703, instance 1, run: true Feb 24 16:09:35 volumio volumio[1066]: info: camilladsp spawned new process with pid 1710, instance 1, run: true Feb 24 16:09:35 volumio volumio[1066]: info: camilladsp spawned new process with pid 1717, instance 1, run: true Feb 24 16:09:35 volumio volumio[1066]: STREAMING PROXY: Starting server on port 3245 Feb 24 16:09:35 volumio volumio[1066]: Node JS runtime: 14 Feb 24 16:09:35 volumio volumio[1066]: info: camilladsp spawned new process with pid 1724, instance 1, run: true Feb 24 16:09:35 volumio volumio[1066]: info: camilladsp spawned new process with pid 1731, instance 1, run: true Feb 24 16:09:36 volumio volumio[1066]: info: camilladsp spawned new process with pid 1738, instance 1, run: true Feb 24 16:09:36 volumio volumio[1066]: info: camilladsp spawned new process with pid 1745, instance 1, run: true Feb 24 16:09:36 volumio volumio[1066]: info: camilladsp spawned new process with pid 1752, instance 1, run: true Feb 24 16:09:36 volumio volumio[1066]: info: camilladsp spawned new process with pid 1759, instance 1, run: true Feb 24 16:09:36 volumio volumio[1066]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 24 16:09:36 volumio volumio[1066]: info: camilladsp spawned new process with pid 1766, instance 1, run: true Feb 24 16:09:36 volumio volumio[1066]: info: camilladsp spawned new process with pid 1773, instance 1, run: true Feb 24 16:09:36 volumio volumio[1066]: info: camilladsp spawned new process with pid 1780, instance 1, run: true Feb 24 16:09:36 volumio volumio[1066]: info: camilladsp spawned new process with pid 1787, instance 1, run: true Feb 24 16:09:36 volumio volumio[1066]: info: camilladsp spawned new process with pid 1794, instance 1, run: true Feb 24 16:09:36 volumio volumio[1066]: info: camilladsp spawned new process with pid 1801, instance 1, run: true Feb 24 16:09:36 volumio volumio[1066]: info: camilladsp spawned new process with pid 1808, instance 1, run: true Feb 24 16:09:36 volumio volumio[1066]: info: camilladsp spawned new process with pid 1816, instance 1, run: true Feb 24 16:09:36 volumio volumio[1066]: info: camilladsp spawned new process with pid 1823, instance 1, run: true Feb 24 16:09:36 volumio volumio[1066]: info: camilladsp spawned new process with pid 1830, instance 1, run: true Feb 24 16:09:37 volumio volumio[1066]: info: camilladsp spawned new process with pid 1839, instance 1, run: true Feb 24 16:09:37 volumio volumio[1066]: info: MyVolumio token set successfully Feb 24 16:09:37 volumio volumio[1066]: info: MYVOLUMIO: Adding device Feb 24 16:09:37 volumio volumio[1066]: info: MYVOLUMIO: Evaluating Server Feb 24 16:09:37 volumio systemd[1]: systemd-timedated.service: Succeeded. Feb 24 16:09:37 volumio volumio[1066]: info: camilladsp spawned new process with pid 1848, instance 1, run: true Feb 24 16:09:37 volumio volumio[1066]: info: camilladsp spawned new process with pid 1855, instance 1, run: true Feb 24 16:09:37 volumio volumio[1066]: info: camilladsp spawned new process with pid 1862, instance 1, run: true Feb 24 16:09:37 volumio volumio[1066]: info: MyVolumio status changed Feb 24 16:09:37 volumio volumio[1066]: info: Streaming services startup Feb 24 16:09:37 volumio volumio[1066]: info: Starting Streaming Daemon Feb 24 16:09:37 volumio volumio[1066]: info: Removing browser output: myVolumio user plan is not superstar Feb 24 16:09:37 volumio volumio[1066]: info: Removing audio output: Feb 24 16:09:37 volumio volumio[1066]: info: Stoppping Tunnel 1 Feb 24 16:09:37 volumio sudo[1886]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 24 16:09:37 volumio sudo[1886]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:37 volumio sudo[1886]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:37 volumio volumio[1066]: error: Cannot start Volumio Streaming Daemon Feb 24 16:09:37 volumio volumio[1066]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 24 16:09:37 volumio volumio[1066]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 24 16:09:37 volumio sudo[1889]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 24 16:09:37 volumio sudo[1889]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:37 volumio sudo[1889]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:37 volumio volumio[1066]: info: camilladsp spawned new process with pid 1891, instance 1, run: true Feb 24 16:09:37 volumio volumio[1066]: info: Remote SSH Stopped Feb 24 16:09:38 volumio volumio[1066]: info: camilladsp spawned new process with pid 1898, instance 1, run: true Feb 24 16:09:38 volumio volumio[1066]: info: camilladsp spawned new process with pid 1905, instance 1, run: true Feb 24 16:09:38 volumio volumio[1066]: info: CoreCommandRouter::Close All Modals sent Feb 24 16:09:38 volumio volumio[1066]: info: camilladsp spawned new process with pid 1912, instance 1, run: true Feb 24 16:09:38 volumio volumio[1066]: info: Setting Geolocation for MyVolumio to eu10 Feb 24 16:09:38 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 16:09:38 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 16:09:38 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 16:09:38 volumio volumio[1066]: info: camilladsp spawned new process with pid 1919, instance 1, run: true Feb 24 16:09:38 volumio volumio[1066]: info: Getting Spotify volume Feb 24 16:09:38 volumio volumio[1066]: info: Spotify volume: 100 Feb 24 16:09:38 volumio volumio[1066]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Feb 24 16:09:38 volumio volumio[1066]: info: camilladsp spawned new process with pid 1926, instance 1, run: true Feb 24 16:09:38 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:38 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:38 volumio volumio[1066]: info: camilladsp spawned new process with pid 1933, instance 1, run: true Feb 24 16:09:38 volumio volumio[1066]: info: camilladsp spawned new process with pid 1940, instance 1, run: true Feb 24 16:09:38 volumio volumio[1066]: info: camilladsp spawned new process with pid 1947, instance 1, run: true Feb 24 16:09:38 volumio volumio[1066]: info: camilladsp spawned new process with pid 1954, instance 1, run: true Feb 24 16:09:38 volumio volumio[1066]: info: camilladsp spawned new process with pid 1961, instance 1, run: true Feb 24 16:09:38 volumio volumio[1066]: info: camilladsp spawned new process with pid 1968, instance 1, run: true Feb 24 16:09:38 volumio volumio[1066]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 24 16:09:38 volumio volumio[1066]: info: camilladsp spawned new process with pid 1975, instance 1, run: true Feb 24 16:09:38 volumio volumio[1066]: info: camilladsp spawned new process with pid 1982, instance 1, run: true Feb 24 16:09:38 volumio volumio[1066]: info: camilladsp spawned new process with pid 1989, instance 1, run: true Feb 24 16:09:39 volumio volumio[1066]: info: camilladsp spawned new process with pid 1996, instance 1, run: true Feb 24 16:09:39 volumio volumio[1066]: info: camilladsp spawned new process with pid 2003, instance 1, run: true Feb 24 16:09:39 volumio volumio[1066]: info: camilladsp spawned new process with pid 2010, instance 1, run: true Feb 24 16:09:39 volumio volumio[1066]: info: camilladsp spawned new process with pid 2017, instance 1, run: true Feb 24 16:09:39 volumio volumio[1066]: info: camilladsp spawned new process with pid 2024, instance 1, run: true Feb 24 16:09:39 volumio volumio[1066]: info: Updating MyVolumio device info Feb 24 16:09:39 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 16:09:39 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 16:09:39 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 16:09:39 volumio volumio[1066]: info: camilladsp spawned new process with pid 2031, instance 1, run: true Feb 24 16:09:39 volumio volumio[1066]: info: camilladsp spawned new process with pid 2038, instance 1, run: true Feb 24 16:09:39 volumio volumio[1066]: info: camilladsp spawned new process with pid 2045, instance 1, run: true Feb 24 16:09:39 volumio volumio[1066]: info: camilladsp spawned new process with pid 2052, instance 1, run: true Feb 24 16:09:39 volumio volumio[1066]: info: camilladsp spawned new process with pid 2059, instance 1, run: true Feb 24 16:09:39 volumio volumio[1066]: info: camilladsp spawned new process with pid 2080, instance 1, run: true Feb 24 16:09:39 volumio volumio[1066]: info: camilladsp spawned new process with pid 2087, instance 1, run: true Feb 24 16:09:39 volumio volumio[1066]: info: AutoStart - Plugin is starting Feb 24 16:09:39 volumio volumio[1066]: info: CoreCommandRouter::volumioGetQueue Feb 24 16:09:39 volumio volumio[1066]: info: CoreStateMachine::getQueue Feb 24 16:09:39 volumio volumio[1066]: info: CorePlayQueue::getQueue Feb 24 16:09:39 volumio volumio[1066]: info: AutoStart - start playing Feb 24 16:09:39 volumio volumio[1066]: info: AutoStart - start playing with no specific position Feb 24 16:09:39 volumio volumio[1066]: info: CoreCommandRouter::volumioPlay Feb 24 16:09:39 volumio volumio[1066]: info: CoreStateMachine::play index 0 Feb 24 16:09:39 volumio volumio[1066]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 16:09:39 volumio volumio[1066]: info: CoreStateMachine::stop Feb 24 16:09:39 volumio volumio[1066]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 16:09:39 volumio volumio[1066]: info: CoreStateMachine::play index undefined Feb 24 16:09:39 volumio volumio[1066]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 16:09:39 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:39 volumio volumio[1066]: info: CoreStateMachine::startPlaybackTimer Feb 24 16:09:39 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:39 volumio volumio[1066]: info: [1740409779689] ControllerSpotify::clearAddPlayTrack Feb 24 16:09:39 volumio volumio[1066]: info: Sending Spotify command with payload to local API: /player/play Feb 24 16:09:39 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 24 16:09:39 volumio volumio[1066]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Feb 24 16:09:39 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Feb 24 16:09:39 volumio volumio[1066]: info: Received Get System Version Feb 24 16:09:39 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 24 16:09:39 volumio volumio[1066]: info: Received Get System Info Feb 24 16:09:39 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 24 16:09:39 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 24 16:09:39 volumio volumio[1066]: info: Discovery: Getting this device information Feb 24 16:09:39 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:39 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:39 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 24 16:09:39 volumio volumio[1066]: info: camilladsp spawned new process with pid 2094, instance 1, run: true Feb 24 16:09:39 volumio go-librespot[1403]: time="2025-02-24T16:09:39+01:00" level=debug msg="resolved context of track" uri="spotify:track:4S1VYqwfkLit9mKVY3MXoo" Feb 24 16:09:39 volumio go-librespot[1403]: time="2025-02-24T16:09:39+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:4S1VYqwfkLit9mKVY3MXoo" Feb 24 16:09:39 volumio go-librespot[1403]: time="2025-02-24T16:09:39+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:4S1VYqwfkLit9mKVY3MXoo" Feb 24 16:09:39 volumio volumio[1066]: info: camilladsp spawned new process with pid 2101, instance 1, run: true Feb 24 16:09:39 volumio volumio[1066]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 24 16:09:39 volumio volumio[1066]: info: camilladsp spawned new process with pid 2108, instance 1, run: true Feb 24 16:09:39 volumio volumio[1066]: info: camilladsp spawned new process with pid 2115, instance 1, run: true Feb 24 16:09:39 volumio go-librespot[1403]: time="2025-02-24T16:09:39+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 24 16:09:39 volumio go-librespot[1403]: time="2025-02-24T16:09:39+01:00" level=trace msg="emitting websocket event: will_play" Feb 24 16:09:39 volumio volumio[1066]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4S1VYqwfkLit9mKVY3MXoo","play_origin":"go-librespot"}} Feb 24 16:09:40 volumio volumio[1066]: info: camilladsp spawned new process with pid 2122, instance 1, run: true Feb 24 16:09:40 volumio go-librespot[1403]: time="2025-02-24T16:09:40+01:00" level=debug msg="selected format OGG_VORBIS_320 (bf0ce67f773f77dd150d6bc62a6ad7f4a53cc57a)" uri="spotify:track:4S1VYqwfkLit9mKVY3MXoo" Feb 24 16:09:40 volumio go-librespot[1403]: time="2025-02-24T16:09:40+01:00" level=debug msg="requested aes key for file bf0ce67f773f77dd150d6bc62a6ad7f4a53cc57a, gid: 4S1VYqwfkLit9mKVY3MXoo" Feb 24 16:09:40 volumio volumio[1066]: info: camilladsp spawned new process with pid 2129, instance 1, run: true Feb 24 16:09:40 volumio volumio[1066]: info: camilladsp spawned new process with pid 2136, instance 1, run: true Feb 24 16:09:40 volumio volumio[1066]: info: camilladsp spawned new process with pid 2143, instance 1, run: true Feb 24 16:09:40 volumio volumio[1066]: info: camilladsp spawned new process with pid 2150, instance 1, run: true Feb 24 16:09:40 volumio volumio[1066]: info: camilladsp spawned new process with pid 2157, instance 1, run: true Feb 24 16:09:40 volumio volumio[1066]: info: camilladsp spawned new process with pid 2164, instance 1, run: true Feb 24 16:09:40 volumio volumio[1066]: info: camilladsp spawned new process with pid 2171, instance 1, run: true Feb 24 16:09:40 volumio volumio[1066]: info: camilladsp spawned new process with pid 2178, instance 1, run: true Feb 24 16:09:40 volumio volumio[1066]: info: camilladsp spawned new process with pid 2185, instance 1, run: true Feb 24 16:09:40 volumio volumio[1066]: info: camilladsp spawned new process with pid 2192, instance 1, run: true Feb 24 16:09:40 volumio volumio[1066]: info: camilladsp spawned new process with pid 2199, instance 1, run: true Feb 24 16:09:40 volumio volumio[1066]: info: camilladsp spawned new process with pid 2206, instance 1, run: true Feb 24 16:09:40 volumio volumio[1066]: info: camilladsp spawned new process with pid 2213, instance 1, run: true Feb 24 16:09:40 volumio volumio[1066]: info: camilladsp spawned new process with pid 2220, instance 1, run: true Feb 24 16:09:40 volumio go-librespot[1403]: time="2025-02-24T16:09:40+01:00" level=debug msg="fetched first chunk of 18, total size is 8955834 bytes" uri="spotify:track:4S1VYqwfkLit9mKVY3MXoo" Feb 24 16:09:40 volumio go-librespot[1403]: time="2025-02-24T16:09:40+01:00" level=debug msg="created new output device" Feb 24 16:09:40 volumio volumio[1066]: info: camilladsp spawned new process with pid 2227, instance 1, run: true Feb 24 16:09:40 volumio go-librespot[1403]: time="2025-02-24T16:09:40+01:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames" Feb 24 16:09:40 volumio go-librespot[1403]: time="2025-02-24T16:09:40+01:00" level=info msg="loaded track \"Forever Young\" (paused: false, position: 0ms, duration: 226706ms, prefetched: false)" uri="spotify:track:4S1VYqwfkLit9mKVY3MXoo" Feb 24 16:09:40 volumio volumio[1066]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Feb 24 16:09:40 volumio volumio[1066]: info: FusionDsp - ---- read samplerate from file: 44100 Feb 24 16:09:40 volumio volumio[1066]: info: camilladsp stopping service pid 2227... Feb 24 16:09:41 volumio volumio[1066]: info: camilladsp service terminated, instance 1 Feb 24 16:09:41 volumio volumio[1066]: info: FusionDsp - If filter freq >samplerate/2 then disable it Feb 24 16:09:41 volumio volumio[1066]: info: camilladsp service started and running in background, instance 1 Feb 24 16:09:41 volumio volumio[1066]: info: camilladsp spawned new process with pid 2238, instance 1, run: true Feb 24 16:09:41 volumio go-librespot[1403]: time="2025-02-24T16:09:41+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 24 16:09:41 volumio go-librespot[1403]: time="2025-02-24T16:09:41+01:00" level=debug msg="fetched chunk 1/17, size: 524288" uri="spotify:track:4S1VYqwfkLit9mKVY3MXoo" Feb 24 16:09:41 volumio volumio[1066]: info: camilladsp spawned new process with pid 2245, instance 1, run: true Feb 24 16:09:41 volumio volumio[1066]: info: camilladsp spawned new process with pid 2252, instance 1, run: true Feb 24 16:09:41 volumio volumio[1066]: info: camilladsp spawned new process with pid 2259, instance 1, run: true Feb 24 16:09:41 volumio go-librespot[1403]: time="2025-02-24T16:09:41+01:00" level=debug msg="fetched chunk 2/17, size: 524288" uri="spotify:track:4S1VYqwfkLit9mKVY3MXoo" Feb 24 16:09:41 volumio volumio[1066]: info: camilladsp spawned new process with pid 2266, instance 1, run: true Feb 24 16:09:41 volumio volumio[1066]: info: camilladsp spawned new process with pid 2273, instance 1, run: true Feb 24 16:09:41 volumio volumio[1066]: info: camilladsp spawned new process with pid 2280, instance 1, run: true Feb 24 16:09:41 volumio volumio[1066]: info: camilladsp spawned new process with pid 2287, instance 1, run: true Feb 24 16:09:41 volumio volumio[1066]: info: camilladsp spawned new process with pid 2294, instance 1, run: true Feb 24 16:09:41 volumio go-librespot[1403]: time="2025-02-24T16:09:41+01:00" level=debug msg="fetched chunk 3/17, size: 524288" uri="spotify:track:4S1VYqwfkLit9mKVY3MXoo" Feb 24 16:09:41 volumio volumio[1066]: info: camilladsp spawned new process with pid 2301, instance 1, run: true Feb 24 16:09:41 volumio volumio[1066]: info: camilladsp spawned new process with pid 2308, instance 1, run: true Feb 24 16:09:41 volumio volumio[1066]: info: camilladsp spawned new process with pid 2315, instance 1, run: true Feb 24 16:09:41 volumio volumio[1066]: info: camilladsp spawned new process with pid 2322, instance 1, run: true Feb 24 16:09:41 volumio volumio[1066]: info: camilladsp spawned new process with pid 2329, instance 1, run: true Feb 24 16:09:41 volumio volumio[1066]: info: camilladsp spawned new process with pid 2336, instance 1, run: true Feb 24 16:09:42 volumio volumio[1066]: info: camilladsp spawned new process with pid 2343, instance 1, run: true Feb 24 16:09:42 volumio volumio[1066]: info: camilladsp spawned new process with pid 2350, instance 1, run: true Feb 24 16:09:42 volumio volumio[1066]: info: camilladsp spawned new process with pid 2357, instance 1, run: true Feb 24 16:09:42 volumio volumio[1066]: info: camilladsp spawned new process with pid 2364, instance 1, run: true Feb 24 16:09:42 volumio volumio[1066]: info: camilladsp spawned new process with pid 2371, instance 1, run: true Feb 24 16:09:42 volumio volumio[1066]: info: camilladsp spawned new process with pid 2378, instance 1, run: true Feb 24 16:09:42 volumio volumio[1066]: info: camilladsp spawned new process with pid 2385, instance 1, run: true Feb 24 16:09:42 volumio volumio[1066]: info: camilladsp spawned new process with pid 2392, instance 1, run: true Feb 24 16:09:42 volumio volumio[1066]: info: camilladsp spawned new process with pid 2399, instance 1, run: true Feb 24 16:09:42 volumio volumio[1066]: info: camilladsp spawned new process with pid 2406, instance 1, run: true Feb 24 16:09:42 volumio volumio[1066]: info: camilladsp spawned new process with pid 2413, instance 1, run: true Feb 24 16:09:42 volumio volumio[1066]: info: camilladsp spawned new process with pid 2420, instance 1, run: true Feb 24 16:09:42 volumio volumio[1066]: info: camilladsp spawned new process with pid 2427, instance 1, run: true Feb 24 16:09:42 volumio volumio[1066]: info: MYVOLUMIO: Adding device Feb 24 16:09:42 volumio volumio[1066]: info: MYVOLUMIO: Evaluating Server Feb 24 16:09:42 volumio volumio[1066]: info: camilladsp spawned new process with pid 2434, instance 1, run: true Feb 24 16:09:42 volumio volumio[1066]: info: camilladsp spawned new process with pid 2441, instance 1, run: true Feb 24 16:09:42 volumio volumio[1066]: info: camilladsp spawned new process with pid 2448, instance 1, run: true Feb 24 16:09:43 volumio volumio[1066]: info: camilladsp spawned new process with pid 2470, instance 1, run: true Feb 24 16:09:43 volumio volumio[1066]: info: camilladsp spawned new process with pid 2477, instance 1, run: true Feb 24 16:09:43 volumio volumio[1066]: info: camilladsp spawned new process with pid 2484, instance 1, run: true Feb 24 16:09:43 volumio volumio[1066]: info: camilladsp spawned new process with pid 2491, instance 1, run: true Feb 24 16:09:43 volumio volumio[1066]: info: camilladsp spawned new process with pid 2498, instance 1, run: true Feb 24 16:09:43 volumio volumio[1066]: info: camilladsp spawned new process with pid 2505, instance 1, run: true Feb 24 16:09:43 volumio volumio[1066]: info: Setting Geolocation for MyVolumio to eu10 Feb 24 16:09:43 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 16:09:43 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 16:09:43 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 16:09:43 volumio volumio[1066]: info: camilladsp spawned new process with pid 2512, instance 1, run: true Feb 24 16:09:44 volumio volumio[1066]: info: camilladsp spawned new process with pid 2519, instance 1, run: true Feb 24 16:09:44 volumio volumio[1066]: info: camilladsp spawned new process with pid 2526, instance 1, run: true Feb 24 16:09:44 volumio volumio[1066]: info: camilladsp spawned new process with pid 2533, instance 1, run: true Feb 24 16:09:44 volumio volumio[1066]: info: camilladsp spawned new process with pid 2540, instance 1, run: true Feb 24 16:09:44 volumio volumio[1066]: info: camilladsp spawned new process with pid 2547, instance 1, run: true Feb 24 16:09:44 volumio volumio[1066]: info: camilladsp spawned new process with pid 2554, instance 1, run: true Feb 24 16:09:44 volumio volumio[1066]: info: camilladsp spawned new process with pid 2561, instance 1, run: true Feb 24 16:09:44 volumio volumio[1066]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 24 16:09:44 volumio volumio[1066]: info: camilladsp spawned new process with pid 2568, instance 1, run: true Feb 24 16:09:44 volumio volumio[1066]: info: camilladsp spawned new process with pid 2575, instance 1, run: true Feb 24 16:09:44 volumio volumio[1066]: info: camilladsp spawned new process with pid 2582, instance 1, run: true Feb 24 16:09:44 volumio volumio[1066]: info: camilladsp spawned new process with pid 2589, instance 1, run: true Feb 24 16:09:44 volumio volumio[1066]: info: camilladsp spawned new process with pid 2596, instance 1, run: true Feb 24 16:09:44 volumio volumio[1066]: info: camilladsp spawned new process with pid 2603, instance 1, run: true Feb 24 16:09:44 volumio volumio[1066]: info: camilladsp spawned new process with pid 2610, instance 1, run: true Feb 24 16:09:44 volumio volumio[1066]: info: camilladsp spawned new process with pid 2617, instance 1, run: true Feb 24 16:09:44 volumio volumio[1066]: info: Updating MyVolumio device info Feb 24 16:09:44 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 16:09:44 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 16:09:44 volumio volumio[1066]: info: camilladsp spawned new process with pid 2624, instance 1, run: true Feb 24 16:09:44 volumio volumio[1066]: info: camilladsp spawned new process with pid 2631, instance 1, run: true Feb 24 16:09:45 volumio volumio[1066]: info: camilladsp spawned new process with pid 2638, instance 1, run: true Feb 24 16:09:45 volumio volumio[1066]: info: camilladsp spawned new process with pid 2648, instance 1, run: true Feb 24 16:09:45 volumio volumio[1066]: info: camilladsp spawned new process with pid 2655, instance 1, run: true Feb 24 16:09:45 volumio volumio[1066]: info: camilladsp spawned new process with pid 2662, instance 1, run: true Feb 24 16:09:45 volumio volumio[1066]: info: camilladsp spawned new process with pid 2669, instance 1, run: true Feb 24 16:09:45 volumio volumio[1066]: info: camilladsp spawned new process with pid 2676, instance 1, run: true Feb 24 16:09:45 volumio volumio[1066]: info: camilladsp spawned new process with pid 2683, instance 1, run: true Feb 24 16:09:45 volumio volumio[1066]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 24 16:09:45 volumio volumio[1066]: info: camilladsp spawned new process with pid 2690, instance 1, run: true Feb 24 16:09:45 volumio volumio[1066]: info: camilladsp spawned new process with pid 2697, instance 1, run: true Feb 24 16:09:45 volumio volumio[1066]: info: camilladsp spawned new process with pid 2704, instance 1, run: true Feb 24 16:09:45 volumio volumio[1066]: info: camilladsp spawned new process with pid 2711, instance 1, run: true Feb 24 16:09:45 volumio volumio[1066]: info: camilladsp spawned new process with pid 2718, instance 1, run: true Feb 24 16:09:45 volumio volumio[1066]: info: camilladsp spawned new process with pid 2725, instance 1, run: true Feb 24 16:09:45 volumio volumio[1066]: info: camilladsp spawned new process with pid 2732, instance 1, run: true Feb 24 16:09:45 volumio volumio[1066]: info: camilladsp spawned new process with pid 2739, instance 1, run: true Feb 24 16:09:45 volumio volumio[1066]: info: camilladsp spawned new process with pid 2746, instance 1, run: true Feb 24 16:09:46 volumio volumio[1066]: info: camilladsp spawned new process with pid 2753, instance 1, run: true Feb 24 16:09:46 volumio volumio[1066]: info: camilladsp spawned new process with pid 2760, instance 1, run: true Feb 24 16:09:46 volumio volumio[1066]: info: camilladsp spawned new process with pid 2767, instance 1, run: true Feb 24 16:09:46 volumio volumio[1066]: info: camilladsp spawned new process with pid 2774, instance 1, run: true Feb 24 16:09:46 volumio volumio[1066]: info: camilladsp spawned new process with pid 2781, instance 1, run: true Feb 24 16:09:46 volumio volumio[1066]: info: camilladsp spawned new process with pid 2788, instance 1, run: true Feb 24 16:09:46 volumio volumio[1066]: info: camilladsp spawned new process with pid 2795, instance 1, run: true Feb 24 16:09:46 volumio volumio[1066]: info: camilladsp spawned new process with pid 2802, instance 1, run: true Feb 24 16:09:46 volumio volumio[1066]: info: camilladsp spawned new process with pid 2809, instance 1, run: true Feb 24 16:09:46 volumio volumio[1066]: info: camilladsp spawned new process with pid 2816, instance 1, run: true Feb 24 16:09:46 volumio volumio[1066]: info: camilladsp spawned new process with pid 2823, instance 1, run: true Feb 24 16:09:46 volumio volumio[1066]: info: camilladsp spawned new process with pid 2830, instance 1, run: true Feb 24 16:09:46 volumio volumio[1066]: info: camilladsp spawned new process with pid 2837, instance 1, run: true Feb 24 16:09:46 volumio volumio[1066]: info: camilladsp spawned new process with pid 2844, instance 1, run: true Feb 24 16:09:46 volumio volumio[1066]: info: camilladsp spawned new process with pid 2851, instance 1, run: true Feb 24 16:09:46 volumio volumio[1066]: info: camilladsp spawned new process with pid 2858, instance 1, run: true Feb 24 16:09:47 volumio volumio[1066]: info: camilladsp spawned new process with pid 2865, instance 1, run: true Feb 24 16:09:47 volumio volumio[1066]: info: camilladsp spawned new process with pid 2872, instance 1, run: true Feb 24 16:09:47 volumio volumio[1066]: info: camilladsp spawned new process with pid 2879, instance 1, run: true Feb 24 16:09:47 volumio volumio[1066]: info: camilladsp spawned new process with pid 2886, instance 1, run: true Feb 24 16:09:47 volumio volumio[1066]: info: camilladsp spawned new process with pid 2893, instance 1, run: true Feb 24 16:09:47 volumio volumio[1066]: info: camilladsp spawned new process with pid 2900, instance 1, run: true Feb 24 16:09:47 volumio volumio[1066]: info: camilladsp spawned new process with pid 2907, instance 1, run: true Feb 24 16:09:47 volumio volumio[1066]: info: camilladsp spawned new process with pid 2914, instance 1, run: true Feb 24 16:09:47 volumio volumio[1066]: info: camilladsp spawned new process with pid 2921, instance 1, run: true Feb 24 16:09:47 volumio volumio[1066]: info: camilladsp spawned new process with pid 2928, instance 1, run: true Feb 24 16:09:47 volumio volumio[1066]: info: camilladsp spawned new process with pid 2935, instance 1, run: true Feb 24 16:09:47 volumio volumio[1066]: info: camilladsp spawned new process with pid 2942, instance 1, run: true Feb 24 16:09:47 volumio volumio[1066]: info: camilladsp spawned new process with pid 2949, instance 1, run: true Feb 24 16:09:47 volumio volumio[1066]: info: camilladsp spawned new process with pid 2956, instance 1, run: true Feb 24 16:09:47 volumio volumio[1066]: info: camilladsp spawned new process with pid 2963, instance 1, run: true Feb 24 16:09:47 volumio volumio[1066]: info: camilladsp spawned new process with pid 2970, instance 1, run: true Feb 24 16:09:47 volumio volumio[1066]: info: camilladsp spawned new process with pid 2977, instance 1, run: true Feb 24 16:09:48 volumio volumio[1066]: info: camilladsp spawned new process with pid 2984, instance 1, run: true Feb 24 16:09:48 volumio volumio[1066]: info: camilladsp spawned new process with pid 2991, instance 1, run: true Feb 24 16:09:48 volumio volumio[1066]: info: camilladsp spawned new process with pid 2998, instance 1, run: true Feb 24 16:09:48 volumio volumio[1066]: info: camilladsp spawned new process with pid 3005, instance 1, run: true Feb 24 16:09:48 volumio volumio[1066]: info: camilladsp spawned new process with pid 3012, instance 1, run: true Feb 24 16:09:48 volumio volumio[1066]: info: camilladsp spawned new process with pid 3019, instance 1, run: true Feb 24 16:09:48 volumio volumio[1066]: info: camilladsp spawned new process with pid 3026, instance 1, run: true Feb 24 16:09:48 volumio volumio[1066]: info: camilladsp spawned new process with pid 3033, instance 1, run: true Feb 24 16:09:48 volumio volumio[1066]: info: camilladsp spawned new process with pid 3040, instance 1, run: true Feb 24 16:09:48 volumio volumio[1066]: info: camilladsp spawned new process with pid 3047, instance 1, run: true Feb 24 16:09:48 volumio volumio[1066]: info: camilladsp spawned new process with pid 3054, instance 1, run: true Feb 24 16:09:48 volumio volumio[1066]: info: camilladsp spawned new process with pid 3061, instance 1, run: true Feb 24 16:09:48 volumio volumio[1066]: info: camilladsp spawned new process with pid 3068, instance 1, run: true Feb 24 16:09:48 volumio volumio[1066]: info: camilladsp spawned new process with pid 3075, instance 1, run: true Feb 24 16:09:48 volumio volumio[1066]: info: camilladsp spawned new process with pid 3082, instance 1, run: true Feb 24 16:09:48 volumio volumio[1066]: info: camilladsp spawned new process with pid 3089, instance 1, run: true Feb 24 16:09:48 volumio volumio[1066]: info: camilladsp spawned new process with pid 3096, instance 1, run: true Feb 24 16:09:48 volumio volumio[1066]: info: camilladsp spawned new process with pid 3103, instance 1, run: true Feb 24 16:09:48 volumio volumio[1066]: info: camilladsp spawned new process with pid 3110, instance 1, run: true Feb 24 16:09:48 volumio volumio[1066]: info: camilladsp spawned new process with pid 3117, instance 1, run: true Feb 24 16:09:48 volumio volumio[1066]: info: camilladsp spawned new process with pid 3124, instance 1, run: true Feb 24 16:09:49 volumio volumio[1066]: info: camilladsp spawned new process with pid 3131, instance 1, run: true Feb 24 16:09:49 volumio volumio[1066]: info: camilladsp spawned new process with pid 3138, instance 1, run: true Feb 24 16:09:49 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 24 16:09:49 volumio volumio[1066]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Feb 24 16:09:49 volumio volumio[1066]: info: camilladsp spawned new process with pid 3145, instance 1, run: true Feb 24 16:09:49 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:09:49 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:49 volumio volumio[1066]: info: camilladsp spawned new process with pid 3152, instance 1, run: true Feb 24 16:09:49 volumio volumio[1066]: info: camilladsp spawned new process with pid 3159, instance 1, run: true Feb 24 16:09:49 volumio volumio[1066]: info: camilladsp spawned new process with pid 3166, instance 1, run: true Feb 24 16:09:49 volumio volumio[1066]: info: camilladsp spawned new process with pid 3173, instance 1, run: true Feb 24 16:09:49 volumio volumio[1066]: info: camilladsp spawned new process with pid 3180, instance 1, run: true Feb 24 16:09:49 volumio volumio[1066]: info: camilladsp spawned new process with pid 3187, instance 1, run: true Feb 24 16:09:49 volumio volumio[1066]: info: camilladsp spawned new process with pid 3194, instance 1, run: true Feb 24 16:09:49 volumio volumio[1066]: info: camilladsp spawned new process with pid 3201, instance 1, run: true Feb 24 16:09:49 volumio volumio[1066]: info: camilladsp spawned new process with pid 3208, instance 1, run: true Feb 24 16:09:49 volumio volumio[1066]: info: camilladsp spawned new process with pid 3215, instance 1, run: true Feb 24 16:09:49 volumio volumio[1066]: info: camilladsp spawned new process with pid 3222, instance 1, run: true Feb 24 16:09:49 volumio volumio[1066]: info: camilladsp spawned new process with pid 3243, instance 1, run: true Feb 24 16:09:49 volumio volumio[1066]: info: camilladsp spawned new process with pid 3250, instance 1, run: true Feb 24 16:09:49 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 24 16:09:49 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 16:09:49 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 24 16:09:49 volumio volumio[1066]: info: camilladsp spawned new process with pid 3259, instance 1, run: true Feb 24 16:09:49 volumio volumio[1066]: info: camilladsp spawned new process with pid 3266, instance 1, run: true Feb 24 16:09:49 volumio volumio[1066]: info: camilladsp spawned new process with pid 3273, instance 1, run: true Feb 24 16:09:49 volumio volumio[1066]: info: camilladsp spawned new process with pid 3280, instance 1, run: true Feb 24 16:09:49 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 24 16:09:49 volumio volumio-remote-updater[687]: No test mode Feb 24 16:09:49 volumio volumio-remote-updater[687]: No alpha test mode Feb 24 16:09:49 volumio volumio[1066]: info: camilladsp spawned new process with pid 3288, instance 1, run: true Feb 24 16:09:49 volumio volumio[1066]: info: camilladsp spawned new process with pid 3295, instance 1, run: true Feb 24 16:09:49 volumio volumio[1066]: info: camilladsp spawned new process with pid 3302, instance 1, run: true Feb 24 16:09:50 volumio volumio[1066]: info: camilladsp spawned new process with pid 3309, instance 1, run: true Feb 24 16:09:50 volumio volumio[1066]: info: camilladsp spawned new process with pid 3316, instance 1, run: true Feb 24 16:09:50 volumio volumio[1066]: info: camilladsp spawned new process with pid 3323, instance 1, run: true Feb 24 16:09:50 volumio volumio[1066]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Feb 24 16:09:50 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 24 16:09:50 volumio volumio[1066]: info: camilladsp spawned new process with pid 3330, instance 1, run: true Feb 24 16:09:50 volumio volumio[1066]: info: camilladsp spawned new process with pid 3337, instance 1, run: true Feb 24 16:09:50 volumio volumio[1066]: info: camilladsp spawned new process with pid 3344, instance 1, run: true Feb 24 16:09:50 volumio volumio[1066]: info: camilladsp spawned new process with pid 3351, instance 1, run: true Feb 24 16:09:50 volumio volumio[1066]: info: camilladsp spawned new process with pid 3358, instance 1, run: true Feb 24 16:09:50 volumio volumio[1066]: info: camilladsp spawned new process with pid 3365, instance 1, run: true Feb 24 16:09:50 volumio volumio[1066]: info: camilladsp spawned new process with pid 3372, instance 1, run: true Feb 24 16:09:50 volumio volumio[1066]: info: camilladsp spawned new process with pid 3379, instance 1, run: true Feb 24 16:09:50 volumio volumio[1066]: info: camilladsp spawned new process with pid 3386, instance 1, run: true Feb 24 16:09:50 volumio volumio[1066]: info: camilladsp spawned new process with pid 3393, instance 1, run: true Feb 24 16:09:50 volumio volumio[1066]: info: camilladsp spawned new process with pid 3400, instance 1, run: true Feb 24 16:09:50 volumio volumio[1066]: info: camilladsp spawned new process with pid 3407, instance 1, run: true Feb 24 16:09:50 volumio volumio[1066]: info: camilladsp spawned new process with pid 3414, instance 1, run: true Feb 24 16:09:50 volumio volumio[1066]: info: camilladsp spawned new process with pid 3421, instance 1, run: true Feb 24 16:09:50 volumio volumio[1066]: info: camilladsp spawned new process with pid 3428, instance 1, run: true Feb 24 16:09:50 volumio volumio[1066]: info: camilladsp spawned new process with pid 3435, instance 1, run: true Feb 24 16:09:50 volumio volumio[1066]: info: camilladsp spawned new process with pid 3442, instance 1, run: true Feb 24 16:09:50 volumio volumio[1066]: info: camilladsp spawned new process with pid 3449, instance 1, run: true Feb 24 16:09:50 volumio volumio[1066]: info: camilladsp spawned new process with pid 3456, instance 1, run: true Feb 24 16:09:50 volumio volumio[1066]: info: camilladsp spawned new process with pid 3463, instance 1, run: true Feb 24 16:09:50 volumio volumio[1066]: info: camilladsp spawned new process with pid 3470, instance 1, run: true Feb 24 16:09:51 volumio volumio[1066]: info: camilladsp spawned new process with pid 3477, instance 1, run: true Feb 24 16:09:51 volumio volumio[1066]: info: camilladsp spawned new process with pid 3488, instance 1, run: true Feb 24 16:09:51 volumio volumio[1066]: info: camilladsp spawned new process with pid 3513, instance 1, run: true Feb 24 16:09:51 volumio volumio[1066]: info: camilladsp spawned new process with pid 3536, instance 1, run: true Feb 24 16:09:51 volumio volumio[1066]: info: camilladsp spawned new process with pid 3543, instance 1, run: true Feb 24 16:09:51 volumio volumio[1066]: info: camilladsp spawned new process with pid 3550, instance 1, run: true Feb 24 16:09:51 volumio volumio[1066]: info: camilladsp spawned new process with pid 3557, instance 1, run: true Feb 24 16:09:51 volumio volumio[1066]: info: camilladsp spawned new process with pid 3564, instance 1, run: true Feb 24 16:09:51 volumio volumio[1066]: info: camilladsp spawned new process with pid 3571, instance 1, run: true Feb 24 16:09:51 volumio volumio[1066]: info: camilladsp spawned new process with pid 3578, instance 1, run: true Feb 24 16:09:51 volumio volumio[1066]: info: camilladsp spawned new process with pid 3585, instance 1, run: true Feb 24 16:09:51 volumio volumio[1066]: info: camilladsp spawned new process with pid 3592, instance 1, run: true Feb 24 16:09:51 volumio volumio[1066]: info: camilladsp spawned new process with pid 3599, instance 1, run: true Feb 24 16:09:51 volumio volumio[1066]: info: camilladsp spawned new process with pid 3606, instance 1, run: true Feb 24 16:09:51 volumio volumio[1066]: info: camilladsp spawned new process with pid 3613, instance 1, run: true Feb 24 16:09:51 volumio volumio[1066]: info: camilladsp spawned new process with pid 3620, instance 1, run: true Feb 24 16:09:51 volumio volumio[1066]: info: camilladsp spawned new process with pid 3627, instance 1, run: true Feb 24 16:09:51 volumio volumio[1066]: info: camilladsp spawned new process with pid 3634, instance 1, run: true Feb 24 16:09:51 volumio volumio[1066]: info: camilladsp spawned new process with pid 3641, instance 1, run: true Feb 24 16:09:51 volumio volumio[1066]: info: camilladsp spawned new process with pid 3648, instance 1, run: true Feb 24 16:09:51 volumio volumio[1066]: info: camilladsp spawned new process with pid 3655, instance 1, run: true Feb 24 16:09:51 volumio volumio[1066]: info: camilladsp spawned new process with pid 3662, instance 1, run: true Feb 24 16:09:51 volumio volumio[1066]: info: camilladsp spawned new process with pid 3669, instance 1, run: true Feb 24 16:09:51 volumio volumio[1066]: info: camilladsp spawned new process with pid 3676, instance 1, run: true Feb 24 16:09:52 volumio volumio[1066]: info: camilladsp spawned new process with pid 3683, instance 1, run: true Feb 24 16:09:52 volumio volumio[1066]: info: camilladsp spawned new process with pid 3690, instance 1, run: true Feb 24 16:09:52 volumio volumio[1066]: info: camilladsp spawned new process with pid 3697, instance 1, run: true Feb 24 16:09:52 volumio volumio[1066]: info: camilladsp spawned new process with pid 3704, instance 1, run: true Feb 24 16:09:52 volumio volumio[1066]: info: camilladsp spawned new process with pid 3711, instance 1, run: true Feb 24 16:09:52 volumio volumio[1066]: info: camilladsp spawned new process with pid 3718, instance 1, run: true Feb 24 16:09:52 volumio volumio[1066]: info: camilladsp spawned new process with pid 3725, instance 1, run: true Feb 24 16:09:52 volumio volumio[1066]: info: camilladsp spawned new process with pid 3732, instance 1, run: true Feb 24 16:09:52 volumio volumio[1066]: info: camilladsp spawned new process with pid 3739, instance 1, run: true Feb 24 16:09:52 volumio volumio[1066]: info: camilladsp spawned new process with pid 3746, instance 1, run: true Feb 24 16:09:52 volumio volumio[1066]: info: camilladsp spawned new process with pid 3753, instance 1, run: true Feb 24 16:09:52 volumio volumio[1066]: info: camilladsp spawned new process with pid 3760, instance 1, run: true Feb 24 16:09:52 volumio volumio[1066]: info: camilladsp spawned new process with pid 3767, instance 1, run: true Feb 24 16:09:52 volumio volumio[1066]: info: camilladsp spawned new process with pid 3774, instance 1, run: true Feb 24 16:09:52 volumio volumio[1066]: info: camilladsp spawned new process with pid 3781, instance 1, run: true Feb 24 16:09:52 volumio volumio[1066]: info: camilladsp spawned new process with pid 3788, instance 1, run: true Feb 24 16:09:52 volumio volumio[1066]: info: camilladsp spawned new process with pid 3795, instance 1, run: true Feb 24 16:09:52 volumio volumio[1066]: info: camilladsp spawned new process with pid 3802, instance 1, run: true Feb 24 16:09:52 volumio volumio[1066]: info: camilladsp spawned new process with pid 3809, instance 1, run: true Feb 24 16:09:52 volumio volumio[1066]: info: camilladsp spawned new process with pid 3816, instance 1, run: true Feb 24 16:09:52 volumio volumio[1066]: info: camilladsp spawned new process with pid 3823, instance 1, run: true Feb 24 16:09:52 volumio volumio[1066]: info: camilladsp spawned new process with pid 3830, instance 1, run: true Feb 24 16:09:52 volumio volumio[1066]: info: camilladsp spawned new process with pid 3837, instance 1, run: true Feb 24 16:09:52 volumio volumio[1066]: info: camilladsp spawned new process with pid 3844, instance 1, run: true Feb 24 16:09:53 volumio volumio[1066]: info: camilladsp spawned new process with pid 3851, instance 1, run: true Feb 24 16:09:53 volumio volumio[1066]: info: camilladsp spawned new process with pid 3858, instance 1, run: true Feb 24 16:09:53 volumio volumio[1066]: info: camilladsp spawned new process with pid 3865, instance 1, run: true Feb 24 16:09:53 volumio volumio[1066]: info: camilladsp spawned new process with pid 3872, instance 1, run: true Feb 24 16:09:53 volumio volumio[1066]: info: camilladsp spawned new process with pid 3879, instance 1, run: true Feb 24 16:09:53 volumio volumio[1066]: info: camilladsp spawned new process with pid 3886, instance 1, run: true Feb 24 16:09:53 volumio volumio[1066]: info: camilladsp spawned new process with pid 3893, instance 1, run: true Feb 24 16:09:53 volumio volumio[1066]: info: camilladsp spawned new process with pid 3900, instance 1, run: true Feb 24 16:09:53 volumio volumio[1066]: info: camilladsp spawned new process with pid 3907, instance 1, run: true Feb 24 16:09:53 volumio volumio[1066]: info: camilladsp spawned new process with pid 3914, instance 1, run: true Feb 24 16:09:53 volumio volumio[1066]: info: camilladsp spawned new process with pid 3921, instance 1, run: true Feb 24 16:09:53 volumio volumio[1066]: info: camilladsp spawned new process with pid 3928, instance 1, run: true Feb 24 16:09:53 volumio volumio[1066]: info: camilladsp spawned new process with pid 3935, instance 1, run: true Feb 24 16:09:53 volumio volumio[1066]: info: camilladsp spawned new process with pid 3942, instance 1, run: true Feb 24 16:09:53 volumio volumio[1066]: info: camilladsp spawned new process with pid 3949, instance 1, run: true Feb 24 16:09:53 volumio volumio[1066]: info: camilladsp spawned new process with pid 3956, instance 1, run: true Feb 24 16:09:53 volumio volumio[1066]: info: camilladsp spawned new process with pid 3963, instance 1, run: true Feb 24 16:09:53 volumio volumio[1066]: info: camilladsp spawned new process with pid 3970, instance 1, run: true Feb 24 16:09:53 volumio volumio[1066]: info: camilladsp spawned new process with pid 3977, instance 1, run: true Feb 24 16:09:53 volumio volumio[1066]: info: camilladsp spawned new process with pid 3984, instance 1, run: true Feb 24 16:09:53 volumio volumio[1066]: info: camilladsp spawned new process with pid 3991, instance 1, run: true Feb 24 16:09:53 volumio volumio[1066]: info: camilladsp spawned new process with pid 3998, instance 1, run: true Feb 24 16:09:53 volumio volumio[1066]: info: camilladsp spawned new process with pid 4005, instance 1, run: true Feb 24 16:09:53 volumio volumio[1066]: info: camilladsp spawned new process with pid 4012, instance 1, run: true Feb 24 16:09:54 volumio volumio[1066]: info: camilladsp spawned new process with pid 4019, instance 1, run: true Feb 24 16:09:54 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:54 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:54 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Feb 24 16:09:54 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Feb 24 16:09:54 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Feb 24 16:09:54 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 24 16:09:54 volumio volumio[1066]: info: CoreCommandRouter::volumioGetBrowseSources Feb 24 16:09:54 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 24 16:09:54 volumio go-librespot[1403]: time="2025-02-24T16:09:54+01:00" level=trace msg="sent dealer ping" Feb 24 16:09:54 volumio volumio[1066]: info: camilladsp spawned new process with pid 4026, instance 1, run: true Feb 24 16:09:54 volumio volumio[1066]: info: camilladsp spawned new process with pid 4033, instance 1, run: true Feb 24 16:09:54 volumio go-librespot[1403]: time="2025-02-24T16:09:54+01:00" level=trace msg="received dealer pong" Feb 24 16:09:54 volumio volumio[1066]: info: camilladsp spawned new process with pid 4040, instance 1, run: true Feb 24 16:09:54 volumio volumio[1066]: info: camilladsp spawned new process with pid 4047, instance 1, run: true Feb 24 16:09:54 volumio volumio[1066]: info: camilladsp spawned new process with pid 4054, instance 1, run: true Feb 24 16:09:54 volumio volumio[1066]: info: camilladsp spawned new process with pid 4061, instance 1, run: true Feb 24 16:09:54 volumio volumio[1066]: info: camilladsp spawned new process with pid 4068, instance 1, run: true Feb 24 16:09:54 volumio volumio[1066]: info: camilladsp spawned new process with pid 4075, instance 1, run: true Feb 24 16:09:54 volumio volumio[1066]: info: camilladsp spawned new process with pid 4082, instance 1, run: true Feb 24 16:09:54 volumio volumio[1066]: info: camilladsp spawned new process with pid 4089, instance 1, run: true Feb 24 16:09:54 volumio volumio[1066]: info: camilladsp spawned new process with pid 4096, instance 1, run: true Feb 24 16:09:54 volumio volumio[1066]: info: camilladsp spawned new process with pid 4103, instance 1, run: true Feb 24 16:09:54 volumio volumio[1066]: info: camilladsp spawned new process with pid 4110, instance 1, run: true Feb 24 16:09:54 volumio volumio[1066]: info: camilladsp spawned new process with pid 4117, instance 1, run: true Feb 24 16:09:54 volumio volumio[1066]: info: camilladsp spawned new process with pid 4124, instance 1, run: true Feb 24 16:09:54 volumio volumio[1066]: info: camilladsp spawned new process with pid 4131, instance 1, run: true Feb 24 16:09:54 volumio volumio[1066]: info: camilladsp spawned new process with pid 4138, instance 1, run: true Feb 24 16:09:54 volumio volumio[1066]: info: camilladsp spawned new process with pid 4145, instance 1, run: true Feb 24 16:09:54 volumio volumio[1066]: info: camilladsp spawned new process with pid 4152, instance 1, run: true Feb 24 16:09:54 volumio volumio[1066]: info: camilladsp spawned new process with pid 4159, instance 1, run: true Feb 24 16:09:54 volumio volumio[1066]: info: camilladsp spawned new process with pid 4166, instance 1, run: true Feb 24 16:09:54 volumio volumio[1066]: info: camilladsp spawned new process with pid 4173, instance 1, run: true Feb 24 16:09:55 volumio volumio[1066]: info: camilladsp spawned new process with pid 4180, instance 1, run: true Feb 24 16:09:55 volumio volumio[1066]: info: camilladsp spawned new process with pid 4187, instance 1, run: true Feb 24 16:09:55 volumio volumio[1066]: info: camilladsp spawned new process with pid 4194, instance 1, run: true Feb 24 16:09:55 volumio volumio[1066]: error: MyVolumio Plugin failed to authenticate in a timely fashion Feb 24 16:09:55 volumio volumio[1066]: info: Completed starting MyVolumio Plugin Feb 24 16:09:55 volumio volumio[1066]: [Metrics] CommandRouter: 48s 40.79ms Feb 24 16:09:55 volumio volumio[1066]: info: CoreCommandRouter::volumiosetStartupVolume Feb 24 16:09:55 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 24 16:09:55 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 24 16:09:55 volumio volumio[1066]: info: CoreCommandRouter::Close All Modals sent Feb 24 16:09:55 volumio volumio[1066]: info: CoreCommandRouter::Close All Modals sent Feb 24 16:09:55 volumio volumio[1066]: info: camilladsp spawned new process with pid 4206, instance 1, run: true Feb 24 16:09:55 volumio volumio[1066]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Feb 24 16:09:55 volumio volumio[1066]: info: FusionDsp - ---- read samplerate from file: 44100 Feb 24 16:09:55 volumio volumio[1066]: info: FusionDsp - If filter freq >samplerate/2 then disable it Feb 24 16:09:55 volumio volumio[1066]: error: FusionDsp - WebSocket error: [object Object] Feb 24 16:09:56 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Feb 24 16:09:56 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 24 16:09:56 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Feb 24 16:09:56 volumio go-librespot[1403]: time="2025-02-24T16:09:56+01:00" level=trace msg="scheduling prefetch in 196s" Feb 24 16:09:56 volumio go-librespot[1403]: time="2025-02-24T16:09:56+01:00" level=trace msg="emitting websocket event: metadata" Feb 24 16:09:56 volumio volumio[1066]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Feb 24 16:09:56 volumio volumio[1066]: 2+39 records in Feb 24 16:09:56 volumio volumio[1066]: 2+39 records out Feb 24 16:09:56 volumio volumio[1066]: 220480 bytes (220 kB, 215 KiB) copied, 0.000638713 s, 345 MB/s Feb 24 16:09:56 volumio volumio[1066]: info: camilladsp spawned new process with pid 4215, instance 1, run: true Feb 24 16:09:56 volumio volumio[1066]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:4S1VYqwfkLit9mKVY3MXoo","name":"Forever Young","artist_names":["Alphaville"],"album_name":"Forever Young","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02b9c4979446c4d39bc08e9503","position":0,"duration":226706,"release_date":"year:1984","track_number":6,"disc_number":1}} Feb 24 16:09:56 volumio volumio[1066]: info: camilladsp spawned new process with pid 4222, instance 1, run: true Feb 24 16:09:56 volumio volumio[1066]: info: camilladsp spawned new process with pid 4229, instance 1, run: true Feb 24 16:09:56 volumio go-librespot[1403]: time="2025-02-24T16:09:56+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 24 16:09:56 volumio go-librespot[1403]: time="2025-02-24T16:09:56+01:00" level=trace msg="emitting websocket event: playing" Feb 24 16:09:56 volumio volumio[1066]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:4S1VYqwfkLit9mKVY3MXoo","play_origin":"go-librespot"}} Feb 24 16:09:56 volumio volumio[1066]: SPOTIFY: PUSH STATE SPOTIFY Feb 24 16:09:56 volumio volumio[1066]: SPOTIFY: {"status":"play","service":"spop","title":"Forever Young","artist":"Alphaville","album":"Forever Young","albumart":"https://i.scdn.co/image/ab67616d00001e02b9c4979446c4d39bc08e9503","uri":"spotify:track:4S1VYqwfkLit9mKVY3MXoo","trackType":"spotify","seek":0,"duration":226,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 24 16:09:56 volumio volumio[1066]: info: CoreCommandRouter::servicePushState Feb 24 16:09:56 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:56 volumio volumio[1066]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Forever Young","artist":"Alphaville","album":"Forever Young","albumart":"https://i.scdn.co/image/ab67616d00001e02b9c4979446c4d39bc08e9503","uri":"spotify:track:4S1VYqwfkLit9mKVY3MXoo","trackType":"spotify","seek":0,"duration":226,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 24 16:09:56 volumio volumio[1066]: verbose: CURRENT POSITION 0 Feb 24 16:09:56 volumio volumio[1066]: info: CoreStateMachine::syncState stateService play Feb 24 16:09:56 volumio volumio[1066]: info: CoreStateMachine::syncState currentStatus stop Feb 24 16:09:56 volumio volumio[1066]: info: camilladsp spawned new process with pid 4236, instance 1, run: true Feb 24 16:09:56 volumio volumio[1066]: info: camilladsp spawned new process with pid 4243, instance 1, run: true Feb 24 16:09:56 volumio volumio[1066]: info: camilladsp spawned new process with pid 4250, instance 1, run: true Feb 24 16:09:56 volumio volumio[1066]: info: camilladsp spawned new process with pid 4257, instance 1, run: true Feb 24 16:09:56 volumio volumio[1066]: info: camilladsp spawned new process with pid 4264, instance 1, run: true Feb 24 16:09:56 volumio volumio[1066]: info: camilladsp spawned new process with pid 4271, instance 1, run: true Feb 24 16:09:56 volumio volumio[1066]: info: camilladsp spawned new process with pid 4278, instance 1, run: true Feb 24 16:09:56 volumio volumio[1066]: info: Enabling plugin touch_display Feb 24 16:09:56 volumio volumio[1066]: info: Loading plugin "touch_display"... Feb 24 16:09:56 volumio volumio[1066]: info: Applying required configuration parameters for plugin touch_display Feb 24 16:09:56 volumio volumio[1066]: info: PLUGIN START: touch_display Feb 24 16:09:56 volumio volumio[1066]: info: Loading i18n strings for locale pl Feb 24 16:09:56 volumio volumio[1066]: info: Plugin mpdoutput has duplicated i18n key SAVE. It is ignored. Feb 24 16:09:56 volumio volumio[1066]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Feb 24 16:09:56 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 24 16:09:56 volumio sudo[4286]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Feb 24 16:09:56 volumio sudo[4286]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:56 volumio sudo[4289]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Feb 24 16:09:56 volumio sudo[4289]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:56 volumio volumio[1066]: SPOTIFY: PUSH STATE SPOTIFY Feb 24 16:09:56 volumio volumio[1066]: SPOTIFY: {"status":"play","service":"spop","title":"Forever Young","artist":"Alphaville","album":"Forever Young","albumart":"https://i.scdn.co/image/ab67616d00001e02b9c4979446c4d39bc08e9503","uri":"spotify:track:4S1VYqwfkLit9mKVY3MXoo","trackType":"spotify","seek":0,"duration":226,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 24 16:09:56 volumio volumio[1066]: info: CoreCommandRouter::servicePushState Feb 24 16:09:56 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:56 volumio volumio[1066]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Forever Young","artist":"Alphaville","album":"Forever Young","albumart":"https://i.scdn.co/image/ab67616d00001e02b9c4979446c4d39bc08e9503","uri":"spotify:track:4S1VYqwfkLit9mKVY3MXoo","trackType":"spotify","seek":0,"duration":226,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 24 16:09:56 volumio volumio[1066]: verbose: CURRENT POSITION 0 Feb 24 16:09:56 volumio volumio[1066]: info: CoreStateMachine::syncState stateService play Feb 24 16:09:56 volumio volumio[1066]: info: CoreStateMachine::syncState currentStatus play Feb 24 16:09:56 volumio volumio[1066]: info: Received an update from plugin. extracting info from payload Feb 24 16:09:56 volumio volumio[1066]: info: CoreStateMachine::pushState Feb 24 16:09:56 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:56 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 16:09:56 volumio volumio[1066]: info: CoreCommandRouter::volumioPushState Feb 24 16:09:56 volumio volumio[1066]: info: CoreStateMachine::pushState Feb 24 16:09:56 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:09:56 volumio volumio[1066]: info: CoreCommandRouter::volumioPushState Feb 24 16:09:56 volumio sudo[4292]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Feb 24 16:09:56 volumio sudo[4292]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:56 volumio volumio[1066]: info: touch_display: Backlight interface detected. Feb 24 16:09:56 volumio volumio[1066]: info: [ASDebug] CurState: play PrevState: stop Feb 24 16:09:56 volumio volumio[1066]: info: [ASDebug] Togle GPIO: ON Feb 24 16:09:56 volumio volumio[1066]: info: [ASDebug] CurState: play PrevState: play Feb 24 16:09:56 volumio systemd[1]: Reloading. Feb 24 16:09:56 volumio sudo[4286]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:56 volumio volumio[1066]: info: camilladsp spawned new process with pid 4294, instance 1, run: true Feb 24 16:09:56 volumio volumio[1066]: info: touch_display: systemctl stop getty@tty1.service succeeded. Feb 24 16:09:56 volumio volumio[1066]: info: touch_display: No Raspberry Pi Foundation touch screen detected. Feb 24 16:09:56 volumio sudo[4305]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Feb 24 16:09:56 volumio sudo[4305]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:56 volumio ntpd[840]: Soliciting pool server 193.70.94.182 Feb 24 16:09:56 volumio sudo[4305]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:56 volumio volumio[1066]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Feb 24 16:09:56 volumio sudo[4316]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+w /sys/class/backlight/10-0045/brightness Feb 24 16:09:56 volumio sudo[4316]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:56 volumio sudo[4316]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:56 volumio volumio[1066]: info: camilladsp spawned new process with pid 4319, instance 1, run: true Feb 24 16:09:56 volumio volumio[1066]: info: touch_display: File permissions for backlight brightness control set. Feb 24 16:09:56 volumio kernel: ws_touchscreen 10-0045: I2C write failed: -5 Feb 24 16:09:56 volumio kernel: ws_touchscreen 10-0045: I2C write failed: -5 Feb 24 16:09:56 volumio volumio[1066]: info: camilladsp spawned new process with pid 4329, instance 1, run: true Feb 24 16:09:57 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. Feb 24 16:09:57 volumio volumio[1066]: info: camilladsp spawned new process with pid 4336, instance 1, run: true Feb 24 16:09:57 volumio volumio[1066]: info: camilladsp spawned new process with pid 4343, instance 1, run: true Feb 24 16:09:57 volumio volumio[1066]: info: camilladsp spawned new process with pid 4350, instance 1, run: true Feb 24 16:09:57 volumio systemd[1]: /data/plugins/music_service/lms/unit/logitechmediaserver.service:7: PIDFile= references path below legacy directory /var/run/, updating /var/run/logitechmediaserver.pid → /run/logitechmediaserver.pid; please update the unit file accordingly. Feb 24 16:09:57 volumio volumio[1066]: info: camilladsp spawned new process with pid 4357, instance 1, run: true Feb 24 16:09:57 volumio volumio[1066]: info: camilladsp spawned new process with pid 4364, instance 1, run: true Feb 24 16:09:57 volumio volumio[1066]: info: camilladsp spawned new process with pid 4371, instance 1, run: true Feb 24 16:09:57 volumio volumio[1066]: info: camilladsp spawned new process with pid 4378, instance 1, run: true Feb 24 16:09:57 volumio volumio[1066]: info: camilladsp spawned new process with pid 4385, instance 1, run: true Feb 24 16:09:57 volumio sudo[4289]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:57 volumio volumio[1066]: info: touch_display: systemctl disable getty@tty1.service succeeded. Feb 24 16:09:57 volumio systemd[1]: Reloading. Feb 24 16:09:57 volumio volumio[1066]: info: camilladsp spawned new process with pid 4392, instance 1, run: true Feb 24 16:09:57 volumio volumio[1066]: info: camilladsp spawned new process with pid 4412, instance 1, run: true Feb 24 16:09:57 volumio volumio[1066]: info: camilladsp spawned new process with pid 4419, instance 1, run: true Feb 24 16:09:57 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. Feb 24 16:09:57 volumio volumio[1066]: info: camilladsp spawned new process with pid 4426, instance 1, run: true Feb 24 16:09:57 volumio volumio[1066]: info: camilladsp spawned new process with pid 4433, instance 1, run: true Feb 24 16:09:57 volumio volumio[1066]: info: camilladsp spawned new process with pid 4440, instance 1, run: true Feb 24 16:09:57 volumio volumio[1066]: info: camilladsp spawned new process with pid 4447, instance 1, run: true Feb 24 16:09:57 volumio ntpd[840]: Soliciting pool server 193.25.222.136 Feb 24 16:09:57 volumio systemd[1]: /data/plugins/music_service/lms/unit/logitechmediaserver.service:7: PIDFile= references path below legacy directory /var/run/, updating /var/run/logitechmediaserver.pid → /run/logitechmediaserver.pid; please update the unit file accordingly. Feb 24 16:09:57 volumio volumio[1066]: info: camilladsp spawned new process with pid 4454, instance 1, run: true Feb 24 16:09:57 volumio volumio[1066]: info: camilladsp spawned new process with pid 4461, instance 1, run: true Feb 24 16:09:57 volumio volumio[1066]: info: camilladsp spawned new process with pid 4468, instance 1, run: true Feb 24 16:09:57 volumio volumio[1066]: info: camilladsp spawned new process with pid 4475, instance 1, run: true Feb 24 16:09:57 volumio sudo[4292]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:57 volumio volumio[1066]: info: camilladsp spawned new process with pid 4482, instance 1, run: true Feb 24 16:09:57 volumio volumio[1066]: info: touch_display: systemctl daemon-reload succeeded. Feb 24 16:09:58 volumio sudo[4490]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Feb 24 16:09:58 volumio sudo[4490]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:09:58 volumio sudo[4490]: pam_unix(sudo:session): session closed for user root Feb 24 16:09:58 volumio volumio[1066]: info: camilladsp spawned new process with pid 4492, instance 1, run: true Feb 24 16:09:58 volumio volumio[1066]: error: touch_display: Failed to start volumio-kiosk.service: Error: Command failed: /usr/bin/sudo /bin/systemctl start volumio-kiosk.service Feb 24 16:09:58 volumio volumio[1066]: Failed to start volumio-kiosk.service: Unit volumio-kiosk.service not found. Feb 24 16:09:58 volumio volumio[1066]: info: Error: Error Feb 24 16:09:58 volumio volumio[1066]: info: camilladsp spawned new process with pid 4499, instance 1, run: true Feb 24 16:09:58 volumio volumio[1066]: info: camilladsp spawned new process with pid 4506, instance 1, run: true Feb 24 16:09:58 volumio volumio[1066]: info: camilladsp spawned new process with pid 4513, instance 1, run: true Feb 24 16:09:58 volumio volumio[1066]: info: camilladsp spawned new process with pid 4520, instance 1, run: true Feb 24 16:09:58 volumio volumio[1066]: info: camilladsp spawned new process with pid 4527, instance 1, run: true Feb 24 16:09:58 volumio volumio[1066]: info: camilladsp spawned new process with pid 4534, instance 1, run: true Feb 24 16:09:58 volumio volumio[1066]: info: camilladsp spawned new process with pid 4541, instance 1, run: true Feb 24 16:09:58 volumio volumio[1066]: info: camilladsp spawned new process with pid 4548, instance 1, run: true Feb 24 16:09:58 volumio volumio[1066]: info: camilladsp spawned new process with pid 4555, instance 1, run: true Feb 24 16:09:58 volumio volumio[1066]: info: camilladsp spawned new process with pid 4562, instance 1, run: true Feb 24 16:09:58 volumio volumio[1066]: info: camilladsp spawned new process with pid 4569, instance 1, run: true Feb 24 16:09:58 volumio volumio[1066]: info: camilladsp spawned new process with pid 4576, instance 1, run: true Feb 24 16:09:58 volumio volumio[1066]: info: camilladsp spawned new process with pid 4583, instance 1, run: true Feb 24 16:09:58 volumio volumio[1066]: info: camilladsp spawned new process with pid 4590, instance 1, run: true Feb 24 16:09:58 volumio volumio[1066]: info: camilladsp spawned new process with pid 4597, instance 1, run: true Feb 24 16:09:58 volumio volumio[1066]: info: camilladsp spawned new process with pid 4604, instance 1, run: true Feb 24 16:09:58 volumio volumio[1066]: info: camilladsp spawned new process with pid 4611, instance 1, run: true Feb 24 16:09:58 volumio ntpd[840]: Soliciting pool server 176.32.165.145 Feb 24 16:09:58 volumio volumio[1066]: info: camilladsp spawned new process with pid 4618, instance 1, run: true Feb 24 16:09:58 volumio ntpd[840]: Soliciting pool server 192.86.14.67 Feb 24 16:09:58 volumio volumio[1066]: info: camilladsp spawned new process with pid 4625, instance 1, run: true Feb 24 16:09:58 volumio ntpd[840]: Soliciting pool server 213.222.217.11 Feb 24 16:09:58 volumio volumio[1066]: info: camilladsp spawned new process with pid 4632, instance 1, run: true Feb 24 16:09:58 volumio volumio[1066]: info: camilladsp spawned new process with pid 4639, instance 1, run: true Feb 24 16:09:58 volumio volumio[1066]: info: camilladsp spawned new process with pid 4646, instance 1, run: true Feb 24 16:09:59 volumio volumio[1066]: info: camilladsp spawned new process with pid 4653, instance 1, run: true Feb 24 16:09:59 volumio volumio[1066]: info: camilladsp spawned new process with pid 4660, instance 1, run: true Feb 24 16:09:59 volumio volumio[1066]: info: camilladsp spawned new process with pid 4667, instance 1, run: true Feb 24 16:09:59 volumio volumio[1066]: info: camilladsp spawned new process with pid 4674, instance 1, run: true Feb 24 16:09:59 volumio volumio[1066]: info: camilladsp spawned new process with pid 4681, instance 1, run: true Feb 24 16:09:59 volumio volumio[1066]: info: camilladsp spawned new process with pid 4688, instance 1, run: true Feb 24 16:09:59 volumio volumio[1066]: info: camilladsp spawned new process with pid 4695, instance 1, run: true Feb 24 16:09:59 volumio volumio[1066]: info: camilladsp spawned new process with pid 4702, instance 1, run: true Feb 24 16:09:59 volumio volumio[1066]: info: camilladsp spawned new process with pid 4709, instance 1, run: true Feb 24 16:09:59 volumio volumio[1066]: info: camilladsp spawned new process with pid 4716, instance 1, run: true Feb 24 16:09:59 volumio volumio[1066]: info: camilladsp spawned new process with pid 4723, instance 1, run: true Feb 24 16:09:59 volumio volumio[1066]: info: camilladsp spawned new process with pid 4730, instance 1, run: true Feb 24 16:09:59 volumio volumio[1066]: info: camilladsp spawned new process with pid 4737, instance 1, run: true Feb 24 16:09:59 volumio volumio[1066]: info: camilladsp spawned new process with pid 4744, instance 1, run: true Feb 24 16:09:59 volumio volumio[1066]: info: camilladsp spawned new process with pid 4751, instance 1, run: true Feb 24 16:09:59 volumio volumio[1066]: info: camilladsp spawned new process with pid 4771, instance 1, run: true Feb 24 16:09:59 volumio volumio[1066]: info: camilladsp spawned new process with pid 4779, instance 1, run: true Feb 24 16:09:59 volumio volumio[1066]: info: camilladsp spawned new process with pid 4786, instance 1, run: true Feb 24 16:09:59 volumio volumio[1066]: info: camilladsp spawned new process with pid 4793, instance 1, run: true Feb 24 16:09:59 volumio ntpd[840]: Soliciting pool server 162.159.200.1 Feb 24 16:09:59 volumio ntpd[840]: Soliciting pool server 178.215.228.24 Feb 24 16:09:59 volumio ntpd[840]: Soliciting pool server 51.68.141.5 Feb 24 16:09:59 volumio volumio[1066]: info: camilladsp spawned new process with pid 4800, instance 1, run: true Feb 24 16:09:59 volumio volumio[1066]: info: camilladsp spawned new process with pid 4807, instance 1, run: true Feb 24 16:09:59 volumio volumio[1066]: info: camilladsp spawned new process with pid 4814, instance 1, run: true Feb 24 16:09:59 volumio volumio[1066]: info: camilladsp spawned new process with pid 4821, instance 1, run: true Feb 24 16:09:59 volumio volumio[1066]: info: camilladsp spawned new process with pid 4828, instance 1, run: true Feb 24 16:10:00 volumio volumio[1066]: info: camilladsp spawned new process with pid 4835, instance 1, run: true Feb 24 16:10:00 volumio volumio[1066]: info: camilladsp spawned new process with pid 4842, instance 1, run: true Feb 24 16:10:00 volumio volumio[1066]: info: camilladsp spawned new process with pid 4849, instance 1, run: true Feb 24 16:10:00 volumio volumio[1066]: info: camilladsp spawned new process with pid 4856, instance 1, run: true Feb 24 16:10:00 volumio volumio[1066]: info: camilladsp spawned new process with pid 4863, instance 1, run: true Feb 24 16:10:00 volumio volumio[1066]: info: camilladsp spawned new process with pid 4870, instance 1, run: true Feb 24 16:10:00 volumio volumio[1066]: info: camilladsp spawned new process with pid 4877, instance 1, run: true Feb 24 16:10:00 volumio volumio[1066]: info: camilladsp spawned new process with pid 4884, instance 1, run: true Feb 24 16:10:00 volumio volumio[1066]: info: camilladsp spawned new process with pid 4891, instance 1, run: true Feb 24 16:10:00 volumio volumio[1066]: info: camilladsp spawned new process with pid 4898, instance 1, run: true Feb 24 16:10:00 volumio volumio[1066]: info: camilladsp spawned new process with pid 4905, instance 1, run: true Feb 24 16:10:00 volumio volumio[1066]: info: camilladsp spawned new process with pid 4912, instance 1, run: true Feb 24 16:10:00 volumio volumio[1066]: info: camilladsp spawned new process with pid 4919, instance 1, run: true Feb 24 16:10:00 volumio volumio[1066]: info: camilladsp spawned new process with pid 4926, instance 1, run: true Feb 24 16:10:00 volumio volumio[1066]: info: camilladsp spawned new process with pid 4933, instance 1, run: true Feb 24 16:10:00 volumio volumio[1066]: info: camilladsp spawned new process with pid 4940, instance 1, run: true Feb 24 16:10:00 volumio volumio[1066]: info: camilladsp spawned new process with pid 4947, instance 1, run: true Feb 24 16:10:00 volumio volumio[1066]: info: camilladsp spawned new process with pid 4954, instance 1, run: true Feb 24 16:10:00 volumio volumio[1066]: info: camilladsp spawned new process with pid 4961, instance 1, run: true Feb 24 16:10:00 volumio ntpd[840]: Soliciting pool server 80.50.102.114 Feb 24 16:10:00 volumio ntpd[840]: Soliciting pool server 162.159.200.123 Feb 24 16:10:00 volumio volumio[1066]: info: camilladsp spawned new process with pid 4968, instance 1, run: true Feb 24 16:10:00 volumio ntpd[840]: Soliciting pool server 213.222.217.10 Feb 24 16:10:00 volumio volumio[1066]: info: camilladsp spawned new process with pid 4975, instance 1, run: true Feb 24 16:10:00 volumio volumio[1066]: info: camilladsp spawned new process with pid 4982, instance 1, run: true Feb 24 16:10:00 volumio volumio[1066]: info: camilladsp spawned new process with pid 4989, instance 1, run: true Feb 24 16:10:00 volumio volumio[1066]: info: camilladsp spawned new process with pid 4996, instance 1, run: true Feb 24 16:10:01 volumio volumio[1066]: info: camilladsp spawned new process with pid 5003, instance 1, run: true Feb 24 16:10:01 volumio volumio[1066]: info: camilladsp spawned new process with pid 5010, instance 1, run: true Feb 24 16:10:01 volumio volumio[1066]: info: camilladsp spawned new process with pid 5017, instance 1, run: true Feb 24 16:10:01 volumio volumio[1066]: info: camilladsp spawned new process with pid 5024, instance 1, run: true Feb 24 16:10:01 volumio volumio[1066]: info: camilladsp spawned new process with pid 5031, instance 1, run: true Feb 24 16:10:01 volumio volumio[1066]: info: camilladsp spawned new process with pid 5038, instance 1, run: true Feb 24 16:10:01 volumio volumio[1066]: info: camilladsp spawned new process with pid 5045, instance 1, run: true Feb 24 16:10:01 volumio volumio[1066]: info: camilladsp spawned new process with pid 5052, instance 1, run: true Feb 24 16:10:01 volumio volumio[1066]: info: camilladsp spawned new process with pid 5059, instance 1, run: true Feb 24 16:10:01 volumio volumio[1066]: info: camilladsp spawned new process with pid 5066, instance 1, run: true Feb 24 16:10:01 volumio volumio[1066]: info: camilladsp spawned new process with pid 5073, instance 1, run: true Feb 24 16:10:01 volumio volumio[1066]: info: camilladsp spawned new process with pid 5080, instance 1, run: true Feb 24 16:10:01 volumio volumio[1066]: info: camilladsp spawned new process with pid 5087, instance 1, run: true Feb 24 16:10:01 volumio volumio[1066]: info: camilladsp spawned new process with pid 5094, instance 1, run: true Feb 24 16:10:01 volumio volumio[1066]: info: camilladsp spawned new process with pid 5101, instance 1, run: true Feb 24 16:10:01 volumio volumio[1066]: info: camilladsp spawned new process with pid 5108, instance 1, run: true Feb 24 16:10:01 volumio volumio[1066]: info: camilladsp spawned new process with pid 5115, instance 1, run: true Feb 24 16:10:01 volumio volumio[1066]: info: camilladsp spawned new process with pid 5122, instance 1, run: true Feb 24 16:10:01 volumio ntpd[840]: Soliciting pool server 150.254.65.62 Feb 24 16:10:01 volumio ntpd[840]: Soliciting pool server 91.212.242.21 Feb 24 16:10:01 volumio ntpd[840]: Soliciting pool server 54.37.233.160 Feb 24 16:10:01 volumio volumio[1066]: info: camilladsp spawned new process with pid 5129, instance 1, run: true Feb 24 16:10:01 volumio volumio[1066]: info: camilladsp spawned new process with pid 5136, instance 1, run: true Feb 24 16:10:01 volumio volumio[1066]: info: camilladsp spawned new process with pid 5143, instance 1, run: true Feb 24 16:10:01 volumio volumio[1066]: info: camilladsp spawned new process with pid 5150, instance 1, run: true Feb 24 16:10:01 volumio volumio[1066]: info: camilladsp spawned new process with pid 5157, instance 1, run: true Feb 24 16:10:01 volumio volumio[1066]: info: camilladsp spawned new process with pid 5164, instance 1, run: true Feb 24 16:10:02 volumio volumio[1066]: info: camilladsp spawned new process with pid 5171, instance 1, run: true Feb 24 16:10:02 volumio volumio[1066]: info: camilladsp spawned new process with pid 5178, instance 1, run: true Feb 24 16:10:02 volumio volumio[1066]: info: camilladsp spawned new process with pid 5185, instance 1, run: true Feb 24 16:10:02 volumio volumio[1066]: info: BOOT COMPLETED Feb 24 16:10:02 volumio volumio[1066]: info: camilladsp spawned new process with pid 5192, instance 1, run: true Feb 24 16:10:02 volumio volumio[1066]: info: camilladsp spawned new process with pid 5199, instance 1, run: true Feb 24 16:10:02 volumio volumio[1066]: info: camilladsp spawned new process with pid 5206, instance 1, run: true Feb 24 16:10:02 volumio volumio[1066]: info: mpdhttpout ---Boot completed detected! Patching mpd now! Feb 24 16:10:02 volumio volumio[1066]: info: mpdhttpout ---Configuration successfully replaced in mpd.conf. Feb 24 16:10:02 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Feb 24 16:10:02 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:10:02 volumio volumio[1066]: info: CoreCommandRouter::volumioPause Feb 24 16:10:02 volumio volumio[1066]: info: CoreStateMachine::pause Feb 24 16:10:02 volumio volumio[1066]: info: CoreStateMachine::stPlaybackTimer Feb 24 16:10:02 volumio volumio[1066]: info: CoreStateMachine::servicePause Feb 24 16:10:02 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Feb 24 16:10:02 volumio volumio[1066]: info: CoreCommandRouter::servicePause Feb 24 16:10:02 volumio volumio[1066]: info: Spotify Received pause Feb 24 16:10:02 volumio volumio[1066]: SPOTIFY: SPOTIFY PAUSE Feb 24 16:10:02 volumio volumio[1066]: SPOTIFY: {"status":"play","position":0,"title":"Forever Young","artist":"Alphaville","album":"Forever Young","albumart":"https://i.scdn.co/image/ab67616d0000b273b9c4979446c4d39bc08e9503","uri":"spotify:track:4S1VYqwfkLit9mKVY3MXoo","trackType":"spotify","codec":"ogg","seek":0,"duration":226,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":true,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Feb 24 16:10:02 volumio volumio[1066]: info: Sending Spotify command to local API: /player/pause Feb 24 16:10:02 volumio volumio[1066]: info: mpdhttpout --- Volumio set on pause Feb 24 16:10:02 volumio volumio[1066]: info: camilladsp spawned new process with pid 5213, instance 1, run: true Feb 24 16:10:02 volumio volumio[1066]: info: camilladsp spawned new process with pid 5220, instance 1, run: true Feb 24 16:10:02 volumio volumio[1066]: info: camilladsp spawned new process with pid 5227, instance 1, run: true Feb 24 16:10:02 volumio volumio[1066]: info: camilladsp spawned new process with pid 5234, instance 1, run: true Feb 24 16:10:02 volumio volumio[1066]: info: camilladsp spawned new process with pid 5241, instance 1, run: true Feb 24 16:10:02 volumio volumio[1066]: info: camilladsp spawned new process with pid 5248, instance 1, run: true Feb 24 16:10:02 volumio volumio[1066]: info: camilladsp spawned new process with pid 5255, instance 1, run: true Feb 24 16:10:02 volumio volumio[1066]: info: camilladsp spawned new process with pid 5262, instance 1, run: true Feb 24 16:10:02 volumio volumio[1066]: info: camilladsp spawned new process with pid 5269, instance 1, run: true Feb 24 16:10:02 volumio volumio[1066]: info: camilladsp spawned new process with pid 5276, instance 1, run: true Feb 24 16:10:02 volumio volumio[1066]: info: camilladsp spawned new process with pid 5283, instance 1, run: true Feb 24 16:10:02 volumio volumio[1066]: info: camilladsp spawned new process with pid 5290, instance 1, run: true Feb 24 16:10:02 volumio ntpd[840]: Soliciting pool server 2001:6a0:0:31::2 Feb 24 16:10:02 volumio volumio[1066]: info: camilladsp spawned new process with pid 5297, instance 1, run: true Feb 24 16:10:02 volumio volumio[1066]: info: camilladsp spawned new process with pid 5304, instance 1, run: true Feb 24 16:10:02 volumio volumio[1066]: info: camilladsp spawned new process with pid 5311, instance 1, run: true Feb 24 16:10:02 volumio volumio[1066]: info: camilladsp spawned new process with pid 5318, instance 1, run: true Feb 24 16:10:02 volumio volumio[1066]: info: camilladsp spawned new process with pid 5325, instance 1, run: true Feb 24 16:10:02 volumio volumio[1066]: info: camilladsp spawned new process with pid 5332, instance 1, run: true Feb 24 16:10:03 volumio volumio[1066]: info: camilladsp spawned new process with pid 5339, instance 1, run: true Feb 24 16:10:03 volumio volumio[1066]: info: camilladsp spawned new process with pid 5346, instance 1, run: true Feb 24 16:10:03 volumio volumio[1066]: info: camilladsp spawned new process with pid 5353, instance 1, run: true Feb 24 16:10:03 volumio volumio[1066]: info: camilladsp spawned new process with pid 5360, instance 1, run: true Feb 24 16:10:03 volumio volumio[1066]: info: camilladsp spawned new process with pid 5367, instance 1, run: true Feb 24 16:10:03 volumio volumio[1066]: info: camilladsp spawned new process with pid 5374, instance 1, run: true Feb 24 16:10:03 volumio volumio[1066]: info: camilladsp spawned new process with pid 5381, instance 1, run: true Feb 24 16:10:03 volumio volumio[1066]: info: camilladsp spawned new process with pid 5388, instance 1, run: true Feb 24 16:10:03 volumio volumio[1066]: info: camilladsp spawned new process with pid 5395, instance 1, run: true Feb 24 16:10:03 volumio volumio[1066]: info: camilladsp spawned new process with pid 5402, instance 1, run: true Feb 24 16:10:03 volumio volumio[1066]: info: camilladsp spawned new process with pid 5409, instance 1, run: true Feb 24 16:10:03 volumio volumio[1066]: info: camilladsp spawned new process with pid 5416, instance 1, run: true Feb 24 16:10:03 volumio volumio[1066]: info: camilladsp spawned new process with pid 5423, instance 1, run: true Feb 24 16:10:03 volumio volumio[1066]: info: camilladsp spawned new process with pid 5430, instance 1, run: true Feb 24 16:10:03 volumio volumio[1066]: info: camilladsp spawned new process with pid 5437, instance 1, run: true Feb 24 16:10:03 volumio volumio[1066]: info: camilladsp spawned new process with pid 5444, instance 1, run: true Feb 24 16:10:03 volumio volumio[1066]: info: camilladsp spawned new process with pid 5451, instance 1, run: true Feb 24 16:10:03 volumio volumio[1066]: info: camilladsp spawned new process with pid 5458, instance 1, run: true Feb 24 16:10:03 volumio volumio[1066]: info: camilladsp spawned new process with pid 5465, instance 1, run: true Feb 24 16:10:03 volumio volumio[1066]: info: camilladsp spawned new process with pid 5472, instance 1, run: true Feb 24 16:10:03 volumio volumio[1066]: info: camilladsp spawned new process with pid 5479, instance 1, run: true Feb 24 16:10:03 volumio volumio[1066]: info: camilladsp spawned new process with pid 5486, instance 1, run: true Feb 24 16:10:03 volumio volumio[1066]: info: camilladsp spawned new process with pid 5493, instance 1, run: true Feb 24 16:10:04 volumio volumio[1066]: info: camilladsp spawned new process with pid 5500, instance 1, run: true Feb 24 16:10:04 volumio volumio[1066]: info: camilladsp spawned new process with pid 5507, instance 1, run: true Feb 24 16:10:04 volumio volumio[1066]: info: camilladsp spawned new process with pid 5514, instance 1, run: true Feb 24 16:10:04 volumio volumio[1066]: info: camilladsp spawned new process with pid 5521, instance 1, run: true Feb 24 16:10:04 volumio volumio[1066]: info: camilladsp spawned new process with pid 5528, instance 1, run: true Feb 24 16:10:04 volumio volumio[1066]: info: camilladsp spawned new process with pid 5535, instance 1, run: true Feb 24 16:10:04 volumio volumio[1066]: info: camilladsp spawned new process with pid 5542, instance 1, run: true Feb 24 16:10:04 volumio volumio[1066]: info: camilladsp spawned new process with pid 5549, instance 1, run: true Feb 24 16:10:04 volumio volumio[1066]: info: camilladsp spawned new process with pid 5556, instance 1, run: true Feb 24 16:10:04 volumio volumio[1066]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Feb 24 16:10:04 volumio sudo[5564]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 24 16:10:04 volumio sudo[5564]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:10:04 volumio systemd[1]: Stopping Music Player Daemon... Feb 24 16:10:04 volumio volumio[1066]: info: camilladsp spawned new process with pid 5566, instance 1, run: true Feb 24 16:10:04 volumio systemd[1]: mpd.service: Succeeded. Feb 24 16:10:04 volumio systemd[1]: Stopped Music Player Daemon. Feb 24 16:10:04 volumio volumio[1066]: info: camilladsp spawned new process with pid 5574, instance 1, run: true Feb 24 16:10:04 volumio systemd[1]: Starting Music Player Daemon... Feb 24 16:10:04 volumio volumio[1066]: info: camilladsp spawned new process with pid 5581, instance 1, run: true Feb 24 16:10:04 volumio volumio[1066]: info: camilladsp spawned new process with pid 5588, instance 1, run: true Feb 24 16:10:04 volumio sudo[5573]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 24 16:10:04 volumio sudo[5573]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:10:04 volumio sudo[5573]: pam_unix(sudo:session): session closed for user root Feb 24 16:10:04 volumio volumio[1066]: info: camilladsp spawned new process with pid 5597, instance 1, run: true Feb 24 16:10:04 volumio volumio[1066]: info: camilladsp spawned new process with pid 5604, instance 1, run: true Feb 24 16:10:04 volumio volumio[1066]: info: camilladsp spawned new process with pid 5611, instance 1, run: true Feb 24 16:10:04 volumio volumio[1066]: info: camilladsp spawned new process with pid 5618, instance 1, run: true Feb 24 16:10:04 volumio volumio[1066]: info: camilladsp spawned new process with pid 5625, instance 1, run: true Feb 24 16:10:05 volumio ntpd[840]: receive: Unexpected origin timestamp 0xeb670a4c.c7c63260 does not match aorg 0000000000.00000000 from server@150.254.65.62 xmt 0xeb670a4d.bb9731a6 Feb 24 16:10:05 volumio ntpd[840]: receive: Unexpected origin timestamp 0xeb670a4c.c7d15344 does not match aorg 0000000000.00000000 from server@193.25.222.136 xmt 0xeb670a4d.bd024a6e Feb 24 16:10:05 volumio ntpd[840]: receive: Unexpected origin timestamp 0xeb670a4c.c7ceb71f does not match aorg 0000000000.00000000 from server@178.215.228.24 xmt 0xeb670a4d.bd8b7d3e Feb 24 16:10:05 volumio volumio[1066]: info: camilladsp spawned new process with pid 5632, instance 1, run: true Feb 24 16:10:05 volumio volumio[1066]: info: camilladsp spawned new process with pid 5639, instance 1, run: true Feb 24 16:10:05 volumio volumio[1066]: info: camilladsp spawned new process with pid 5646, instance 1, run: true Feb 24 16:10:05 volumio volumio[1066]: info: camilladsp spawned new process with pid 5653, instance 1, run: true Feb 24 16:10:05 volumio volumio[1066]: info: camilladsp spawned new process with pid 5660, instance 1, run: true Feb 24 16:10:05 volumio volumio[1066]: info: camilladsp spawned new process with pid 5667, instance 1, run: true Feb 24 16:10:06 volumio volumio[1066]: info: camilladsp spawned new process with pid 5674, instance 1, run: true Feb 24 16:10:06 volumio volumio[1066]: info: camilladsp spawned new process with pid 5683, instance 1, run: true Feb 24 16:10:06 volumio volumio[1066]: info: camilladsp spawned new process with pid 5690, instance 1, run: true Feb 24 16:10:06 volumio volumio[1066]: info: camilladsp spawned new process with pid 5697, instance 1, run: true Feb 24 16:10:06 volumio volumio[1066]: info: camilladsp spawned new process with pid 5704, instance 1, run: true Feb 24 16:10:06 volumio mpd[5596]: Feb 24 16:10 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 24 16:10:06 volumio systemd[1]: Started Music Player Daemon. Feb 24 16:10:06 volumio volumio[1066]: info: camilladsp spawned new process with pid 5711, instance 1, run: true Feb 24 16:10:06 volumio sudo[5564]: pam_unix(sudo:session): session closed for user root Feb 24 16:10:06 volumio volumio[1066]: error: updateQueue error: null Feb 24 16:10:06 volumio volumio[1066]: info: camilladsp spawned new process with pid 5721, instance 1, run: true Feb 24 16:10:06 volumio volumio[1066]: info: camilladsp spawned new process with pid 5728, instance 1, run: true Feb 24 16:10:06 volumio volumio[1066]: info: camilladsp spawned new process with pid 5735, instance 1, run: true Feb 24 16:10:06 volumio volumio[1066]: info: camilladsp spawned new process with pid 5742, instance 1, run: true Feb 24 16:10:06 volumio volumio[1066]: info: camilladsp spawned new process with pid 5749, instance 1, run: true Feb 24 16:10:06 volumio volumio[1066]: info: camilladsp spawned new process with pid 5756, instance 1, run: true Feb 24 16:10:06 volumio volumio[1066]: info: camilladsp spawned new process with pid 5763, instance 1, run: true Feb 24 16:10:06 volumio volumio[1066]: info: camilladsp spawned new process with pid 5770, instance 1, run: true Feb 24 16:10:06 volumio volumio[1066]: info: camilladsp spawned new process with pid 5777, instance 1, run: true Feb 24 16:10:06 volumio volumio[1066]: info: camilladsp spawned new process with pid 5784, instance 1, run: true Feb 24 16:10:06 volumio volumio[1066]: info: camilladsp spawned new process with pid 5791, instance 1, run: true Feb 24 16:10:06 volumio volumio[1066]: info: camilladsp spawned new process with pid 5798, instance 1, run: true Feb 24 16:10:06 volumio volumio[1066]: info: camilladsp spawned new process with pid 5805, instance 1, run: true Feb 24 16:10:06 volumio volumio[1066]: info: camilladsp spawned new process with pid 5812, instance 1, run: true Feb 24 16:10:06 volumio volumio[1066]: info: camilladsp spawned new process with pid 5819, instance 1, run: true Feb 24 16:10:06 volumio volumio[1066]: info: camilladsp spawned new process with pid 5826, instance 1, run: true Feb 24 16:10:06 volumio volumio[1066]: info: camilladsp spawned new process with pid 5833, instance 1, run: true Feb 24 16:10:07 volumio volumio[1066]: info: camilladsp spawned new process with pid 5840, instance 1, run: true Feb 24 16:10:07 volumio volumio[1066]: info: camilladsp spawned new process with pid 5847, instance 1, run: true Feb 24 16:10:07 volumio volumio[1066]: info: camilladsp spawned new process with pid 5854, instance 1, run: true Feb 24 16:10:07 volumio volumio[1066]: info: camilladsp spawned new process with pid 5861, instance 1, run: true Feb 24 16:10:07 volumio volumio[1066]: info: camilladsp spawned new process with pid 5868, instance 1, run: true Feb 24 16:10:07 volumio volumio[1066]: info: camilladsp spawned new process with pid 5875, instance 1, run: true Feb 24 16:10:07 volumio volumio[1066]: info: camilladsp spawned new process with pid 5882, instance 1, run: true Feb 24 16:10:07 volumio volumio[1066]: info: camilladsp spawned new process with pid 5889, instance 1, run: true Feb 24 16:10:07 volumio volumio[1066]: info: camilladsp spawned new process with pid 5896, instance 1, run: true Feb 24 16:10:07 volumio volumio[1066]: info: camilladsp spawned new process with pid 5903, instance 1, run: true Feb 24 16:10:07 volumio volumio[1066]: info: camilladsp spawned new process with pid 5910, instance 1, run: true Feb 24 16:10:07 volumio volumio[1066]: info: camilladsp spawned new process with pid 5917, instance 1, run: true Feb 24 16:10:07 volumio volumio[1066]: info: camilladsp spawned new process with pid 5924, instance 1, run: true Feb 24 16:10:07 volumio volumio[1066]: info: camilladsp spawned new process with pid 5931, instance 1, run: true Feb 24 16:10:07 volumio volumio[1066]: info: camilladsp spawned new process with pid 5938, instance 1, run: true Feb 24 16:10:07 volumio volumio[1066]: info: camilladsp spawned new process with pid 5945, instance 1, run: true Feb 24 16:10:07 volumio volumio[1066]: info: camilladsp spawned new process with pid 5952, instance 1, run: true Feb 24 16:10:07 volumio volumio[1066]: info: camilladsp spawned new process with pid 5959, instance 1, run: true Feb 24 16:10:07 volumio volumio[1066]: info: camilladsp spawned new process with pid 5966, instance 1, run: true Feb 24 16:10:07 volumio volumio[1066]: info: camilladsp spawned new process with pid 5973, instance 1, run: true Feb 24 16:10:07 volumio volumio[1066]: info: camilladsp spawned new process with pid 5980, instance 1, run: true Feb 24 16:10:07 volumio volumio[1066]: info: camilladsp spawned new process with pid 5987, instance 1, run: true Feb 24 16:10:07 volumio volumio[1066]: info: camilladsp spawned new process with pid 5994, instance 1, run: true Feb 24 16:10:07 volumio volumio[1066]: info: camilladsp spawned new process with pid 6001, instance 1, run: true Feb 24 16:10:08 volumio volumio[1066]: info: camilladsp spawned new process with pid 6008, instance 1, run: true Feb 24 16:10:08 volumio volumio[1066]: info: camilladsp spawned new process with pid 6015, instance 1, run: true Feb 24 16:10:08 volumio volumio[1066]: info: camilladsp spawned new process with pid 6022, instance 1, run: true Feb 24 16:10:08 volumio volumio[1066]: info: camilladsp spawned new process with pid 6029, instance 1, run: true Feb 24 16:10:08 volumio volumio[1066]: info: camilladsp spawned new process with pid 6036, instance 1, run: true Feb 24 16:10:08 volumio volumio[1066]: info: camilladsp spawned new process with pid 6043, instance 1, run: true Feb 24 16:10:08 volumio volumio[1066]: info: camilladsp spawned new process with pid 6050, instance 1, run: true Feb 24 16:10:08 volumio volumio[1066]: info: camilladsp spawned new process with pid 6057, instance 1, run: true Feb 24 16:10:08 volumio volumio[1066]: info: camilladsp spawned new process with pid 6064, instance 1, run: true Feb 24 16:10:08 volumio volumio[1066]: info: camilladsp spawned new process with pid 6071, instance 1, run: true Feb 24 16:10:08 volumio volumio[1066]: info: camilladsp spawned new process with pid 6078, instance 1, run: true Feb 24 16:10:08 volumio volumio[1066]: info: camilladsp spawned new process with pid 6085, instance 1, run: true Feb 24 16:10:08 volumio volumio[1066]: info: camilladsp spawned new process with pid 6092, instance 1, run: true Feb 24 16:10:08 volumio volumio[1066]: info: camilladsp spawned new process with pid 6099, instance 1, run: true Feb 24 16:10:08 volumio volumio[1066]: info: camilladsp spawned new process with pid 6106, instance 1, run: true Feb 24 16:10:08 volumio volumio[1066]: info: camilladsp spawned new process with pid 6113, instance 1, run: true Feb 24 16:10:08 volumio volumio[1066]: info: camilladsp spawned new process with pid 6120, instance 1, run: true Feb 24 16:10:08 volumio volumio[1066]: info: camilladsp spawned new process with pid 6127, instance 1, run: true Feb 24 16:10:08 volumio volumio[1066]: info: camilladsp spawned new process with pid 6134, instance 1, run: true Feb 24 16:10:08 volumio volumio[1066]: info: camilladsp spawned new process with pid 6141, instance 1, run: true Feb 24 16:10:08 volumio volumio[1066]: info: camilladsp spawned new process with pid 6148, instance 1, run: true Feb 24 16:10:08 volumio volumio[1066]: info: camilladsp spawned new process with pid 6155, instance 1, run: true Feb 24 16:10:08 volumio volumio[1066]: info: camilladsp spawned new process with pid 6162, instance 1, run: true Feb 24 16:10:09 volumio volumio[1066]: info: camilladsp spawned new process with pid 6169, instance 1, run: true Feb 24 16:10:09 volumio volumio[1066]: info: camilladsp spawned new process with pid 6176, instance 1, run: true Feb 24 16:10:09 volumio volumio[1066]: info: camilladsp spawned new process with pid 6183, instance 1, run: true Feb 24 16:10:09 volumio volumio[1066]: info: camilladsp spawned new process with pid 6190, instance 1, run: true Feb 24 16:10:09 volumio volumio[1066]: info: camilladsp spawned new process with pid 6197, instance 1, run: true Feb 24 16:10:09 volumio volumio[1066]: info: camilladsp spawned new process with pid 6204, instance 1, run: true Feb 24 16:10:09 volumio volumio[1066]: info: camilladsp spawned new process with pid 6211, instance 1, run: true Feb 24 16:10:09 volumio volumio[1066]: info: camilladsp spawned new process with pid 6218, instance 1, run: true Feb 24 16:10:09 volumio volumio[1066]: info: camilladsp spawned new process with pid 6225, instance 1, run: true Feb 24 16:10:09 volumio volumio[1066]: info: camilladsp spawned new process with pid 6232, instance 1, run: true Feb 24 16:10:09 volumio volumio[1066]: info: camilladsp spawned new process with pid 6239, instance 1, run: true Feb 24 16:10:09 volumio volumio[1066]: info: camilladsp spawned new process with pid 6246, instance 1, run: true Feb 24 16:10:09 volumio volumio[1066]: info: camilladsp spawned new process with pid 6253, instance 1, run: true Feb 24 16:10:09 volumio volumio[1066]: info: camilladsp spawned new process with pid 6260, instance 1, run: true Feb 24 16:10:09 volumio volumio[1066]: info: camilladsp spawned new process with pid 6267, instance 1, run: true Feb 24 16:10:09 volumio volumio[1066]: info: camilladsp spawned new process with pid 6274, instance 1, run: true Feb 24 16:10:09 volumio volumio[1066]: info: camilladsp spawned new process with pid 6281, instance 1, run: true Feb 24 16:10:09 volumio volumio[1066]: info: camilladsp spawned new process with pid 6288, instance 1, run: true Feb 24 16:10:09 volumio volumio[1066]: info: camilladsp spawned new process with pid 6295, instance 1, run: true Feb 24 16:10:09 volumio volumio[1066]: info: camilladsp spawned new process with pid 6302, instance 1, run: true Feb 24 16:10:09 volumio volumio[1066]: info: camilladsp spawned new process with pid 6309, instance 1, run: true Feb 24 16:10:09 volumio volumio[1066]: info: camilladsp spawned new process with pid 6316, instance 1, run: true Feb 24 16:10:09 volumio volumio[1066]: info: camilladsp spawned new process with pid 6323, instance 1, run: true Feb 24 16:10:09 volumio volumio[1066]: info: camilladsp spawned new process with pid 6330, instance 1, run: true Feb 24 16:10:10 volumio volumio[1066]: info: camilladsp spawned new process with pid 6337, instance 1, run: true Feb 24 16:10:10 volumio volumio[1066]: info: camilladsp spawned new process with pid 6344, instance 1, run: true Feb 24 16:10:10 volumio volumio[1066]: info: camilladsp spawned new process with pid 6351, instance 1, run: true Feb 24 16:10:10 volumio volumio[1066]: info: camilladsp spawned new process with pid 6358, instance 1, run: true Feb 24 16:10:10 volumio volumio[1066]: info: camilladsp spawned new process with pid 6365, instance 1, run: true Feb 24 16:10:10 volumio volumio[1066]: info: camilladsp spawned new process with pid 6372, instance 1, run: true Feb 24 16:10:10 volumio volumio[1066]: info: camilladsp spawned new process with pid 6379, instance 1, run: true Feb 24 16:10:10 volumio volumio[1066]: info: camilladsp spawned new process with pid 6386, instance 1, run: true Feb 24 16:10:10 volumio volumio[1066]: info: camilladsp spawned new process with pid 6393, instance 1, run: true Feb 24 16:10:10 volumio volumio[1066]: info: camilladsp spawned new process with pid 6400, instance 1, run: true Feb 24 16:10:10 volumio volumio[1066]: info: camilladsp spawned new process with pid 6407, instance 1, run: true Feb 24 16:10:10 volumio volumio[1066]: info: camilladsp spawned new process with pid 6414, instance 1, run: true Feb 24 16:10:10 volumio volumio[1066]: info: camilladsp spawned new process with pid 6421, instance 1, run: true Feb 24 16:10:10 volumio volumio[1066]: info: camilladsp spawned new process with pid 6428, instance 1, run: true Feb 24 16:10:10 volumio volumio[1066]: info: Starting Uninstall of plugin user_interface - touch_display Feb 24 16:10:10 volumio volumio[1066]: info: Uninstalling plugin touch_display Feb 24 16:10:10 volumio sudo[6438]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Feb 24 16:10:10 volumio sudo[6438]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:10:10 volumio sudo[6438]: pam_unix(sudo:session): session closed for user root Feb 24 16:10:10 volumio sudo[6450]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start getty@tty1.service Feb 24 16:10:10 volumio sudo[6450]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:10:10 volumio sudo[6456]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl enable getty@tty1.service Feb 24 16:10:10 volumio sudo[6456]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:10:10 volumio volumio[1066]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set. Feb 24 16:10:10 volumio volumio[1066]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 24 16:10:10 volumio volumio[1066]: TypeError: Cannot read property 'split' of undefined Feb 24 16:10:10 volumio volumio[1066]: at /data/plugins/user_interface/touch_display/index.js:1258:37 Feb 24 16:10:10 volumio volumio[1066]: at ChildProcess.exithandler (child_process.js:299:7) Feb 24 16:10:10 volumio volumio[1066]: at ChildProcess.emit (events.js:315:20) Feb 24 16:10:10 volumio volumio[1066]: at maybeClose (internal/child_process.js:1048:16) Feb 24 16:10:10 volumio volumio[1066]: at Socket. (internal/child_process.js:439:11) Feb 24 16:10:10 volumio volumio[1066]: at Socket.emit (events.js:315:20) Feb 24 16:10:10 volumio volumio[1066]: at Pipe. (net.js:673:12) Feb 24 16:10:10 volumio volumio[1066]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 24 16:10:10 volumio sudo[6459]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumio-kiosk.service Feb 24 16:10:10 volumio systemd[1]: Created slice system-getty.slice. Feb 24 16:10:10 volumio sudo[6459]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:10:10 volumio systemd[1]: Started Getty on tty1. Feb 24 16:10:10 volumio sudo[6450]: pam_unix(sudo:session): session closed for user root Feb 24 16:10:10 volumio systemd[1]: Reloading. Feb 24 16:10:10 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. Feb 24 16:10:11 volumio systemd[1]: getty@tty1.service: Current command vanished from the unit file, execution of the command list won't be resumed. Feb 24 16:10:11 volumio sudo[6484]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-02-24 16:09 Feb 24 16:10:11 volumio sudo[6484]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 24 16:10:11 volumio systemd[1]: /data/plugins/music_service/lms/unit/logitechmediaserver.service:7: PIDFile= references path below legacy directory /var/run/, updating /var/run/logitechmediaserver.pid → /run/logitechmediaserver.pid; please update the unit file accordingly. 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"