-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Fri 2026-03-27 23:42:31 CET. -- Mar 27 23:41:00 volumio volumio[931]: info: Applying required configuration parameters for plugin minidlna Mar 27 23:41:00 volumio volumio[931]: info: Loading plugin "motherearthradio"... Mar 27 23:41:00 volumio volumio[931]: info: Applying required configuration parameters for plugin motherearthradio Mar 27 23:41:00 volumio volumio[931]: info: [1774651260958] [MotherEarth] API delay: 5 Mar 27 23:41:00 volumio volumio[931]: info: Loading plugin "podcast"... Mar 27 23:41:01 volumio volumio[931]: info: ControllerPodcast::constructor Mar 27 23:41:01 volumio volumio[931]: info: Loading plugin "radio_paradise"... Mar 27 23:41:02 volumio volumio[931]: info: Applying required configuration parameters for plugin radio_paradise Mar 27 23:41:02 volumio volumio[931]: info: [1774651262113] [RadioParadise] API delay: 5 Mar 27 23:41:02 volumio volumio[931]: info: Loading plugin "audiophonicsonoff"... Mar 27 23:41:02 volumio volumio[931]: info: Applying required configuration parameters for plugin audiophonicsonoff Mar 27 23:41:02 volumio volumio[931]: info: Audiophonics on/off initiated Mar 27 23:41:02 volumio volumio[931]: info: Loading plugin "Systeminfo"... Mar 27 23:41:03 volumio volumio[931]: info: Loading plugin "lastfm"... Mar 27 23:41:04 volumio volumio[931]: info: Loading plugin "peppymeterbasic"... Mar 27 23:41:05 volumio volumio[931]: info: Loading i18n strings for locale fr Mar 27 23:41:05 volumio volumio[931]: info: Plugin mpdoutput has duplicated i18n key SAVE. It is ignored. Mar 27 23:41:05 volumio volumio[931]: info: Plugin peppymeterbasic has duplicated i18n key APPLY. It is ignored. Mar 27 23:41:05 volumio volumio[931]: info: Plugin peppymeterbasic has duplicated i18n key SAVE. It is ignored. Mar 27 23:41:05 volumio volumio[931]: info: Plugin peppymeterbasic has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. Mar 27 23:41:05 volumio volumio[931]: info: Plugin peppymeterbasic has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. Mar 27 23:41:05 volumio volumio[931]: Updating browse sources language Mar 27 23:41:05 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 27 23:41:05 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 27 23:41:05 volumio volumio[931]: info: CoreCommandRouter::initPlayerControls Mar 27 23:41:05 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:05 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:05 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:05 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:05 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:05 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:05 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:05 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:05 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 27 23:41:05 volumio volumio[931]: Express server listening on port 3000 Mar 27 23:41:05 volumio volumio[931]: [Metrics] WebUI: 42s 241.10ms Mar 27 23:41:05 volumio volumio[931]: info: CoreStateMachine::resetVolumioState Mar 27 23:41:05 volumio volumio[931]: info: CoreStateMachine::getcurrentVolume Mar 27 23:41:05 volumio volumio[931]: info: CoreCommandRouter::volumioRetrievevolume Mar 27 23:41:05 volumio sudo[1246]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 27 23:41:05 volumio sudo[1246]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:05 volumio sudo[1246]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:05 volumio sudo[1248]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 27 23:41:05 volumio sudo[1248]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:05 volumio sudo[1248]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:05 volumio volumio[931]: info: Volumio Network Manager: Network status updated: 1 Mar 27 23:41:05 volumio volumio[931]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Mar 27 23:41:05 volumio volumio[931]: info: VolumeController:: Volume=63 Mute =false Mar 27 23:41:05 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:05 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:05 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 27 23:41:05 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:05 volumio volumio[931]: info: CoreStateMachine::updateTrackBlock Mar 27 23:41:05 volumio volumio[931]: info: CorePlayQueue::getTrackBlock Mar 27 23:41:05 volumio volumio[931]: info: CoreCommandRouter::volumioRetrievevolume Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 23:41:06 volumio volumio[931]: info: Reloading queue from file Mar 27 23:41:06 volumio volumio[931]: info: Setting Device type: Raspberry PI Mar 27 23:41:06 volumio volumio[931]: info: CoreStateMachine::setRepeat true single undefined Mar 27 23:41:06 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:06 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:06 volumio volumio[931]: info: CoreStateMachine::setRandom true Mar 27 23:41:06 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:06 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:06 volumio sudo[1261]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 27 23:41:06 volumio sudo[1261]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:06 volumio volumio[931]: info: VolumeController:: Volume=63 Mute =false Mar 27 23:41:06 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:06 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:06 volumio volumio[931]: info: Discovery: adding e388eb39-58e3-4fd9-88e6-a66a01b70549 Mar 27 23:41:06 volumio volumio[931]: info: Discovery: Found device Volumio Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Mar 27 23:41:06 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:06 volumio volumio[931]: info: Discovery: this is already registered, e388eb39-58e3-4fd9-88e6-a66a01b70549 Mar 27 23:41:06 volumio volumio[931]: info: Discovery: Found device Volumio Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Mar 27 23:41:06 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:06 volumio volumio[931]: info: Completed loading Core Plugins Mar 27 23:41:06 volumio volumio[931]: info: Preparing to generate the ALSA configuration file Mar 27 23:41:06 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Mar 27 23:41:06 volumio sudo[1261]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:06 volumio volumio[931]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Mar 27 23:41:06 volumio volumio[931]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Mar 27 23:41:06 volumio volumio[931]: info: Reading ALSA contributions from plugins. Mar 27 23:41:06 volumio volumio[931]: info: Upmpdcli Daemon Started Mar 27 23:41:06 volumio volumio[931]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 Mar 27 23:41:06 volumio volumio[931]: info: Asound.conf file unchanged, so no further update is needed Mar 27 23:41:06 volumio volumio[931]: info: Output device has changed, restarting MPD Mar 27 23:41:06 volumio volumio[931]: info: Output device has changed, restarting Shairport Sync Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 23:41:06 volumio sudo[1265]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 27 23:41:06 volumio sudo[1265]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:06 volumio sudo[1265]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:06 volumio sudo[1267]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 27 23:41:06 volumio sudo[1267]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:06 volumio volumio[931]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 27 23:41:06 volumio volumio[931]: info: ___________ START PLUGINS ___________ Mar 27 23:41:06 volumio volumio[931]: info: ControllerMpd::onStart: Initializing MPD Mar 27 23:41:06 volumio volumio[931]: info: Creating MPD Configuration file Mar 27 23:41:06 volumio systemd[1]: Listening on mpd.socket. Mar 27 23:41:06 volumio systemd[1]: Starting Music Player Daemon... Mar 27 23:41:06 volumio sudo[1275]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Mar 27 23:41:06 volumio sudo[1275]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 27 23:41:06 volumio volumio[931]: info: [1774651266550] CoreMusicLibrary::Adding element Serveurs Média Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 27 23:41:06 volumio sudo[1277]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 27 23:41:06 volumio sudo[1277]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:06 volumio volumio[931]: info: UPNP Browser: Client initialized successfully Mar 27 23:41:06 volumio systemd[1]: Started Volumio5 Onboarding Server. Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 23:41:06 volumio sudo[1275]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:06 volumio sudo[1281]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 27 23:41:06 volumio sudo[1281]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:06 volumio sudo[1277]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:06 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Mar 27 23:41:06 volumio systemd[1]: mpd.service: Succeeded. Mar 27 23:41:06 volumio systemd[1]: Stopped Music Player Daemon. Mar 27 23:41:06 volumio systemd[1]: Starting Music Player Daemon... Mar 27 23:41:06 volumio volumio[931]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 23:41:06 volumio volumio[931]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 27 23:41:06 volumio volumio[931]: info: [1774651266737] CoreMusicLibrary::Adding element Last_100 Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 27 23:41:06 volumio volumio[931]: info: [1774651266741] CoreMusicLibrary::Adding element Webradio Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 27 23:41:06 volumio volumio[931]: info: Initializing BBC Radios Mar 27 23:41:06 volumio sudo[1288]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 27 23:41:06 volumio sudo[1288]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:06 volumio sudo[1288]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Mar 27 23:41:06 volumio sudo[1288]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 27 23:41:06 volumio volumio[931]: info: [1774651266887] CoreMusicLibrary::Adding element Bandcamp Discover Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 27 23:41:06 volumio volumio[931]: Cannot find translation for source Bandcamp Discover Mar 27 23:41:06 volumio volumio[931]: info: Adding Calm Radio to Browse Sources Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 27 23:41:06 volumio volumio[931]: info: [1774651266893] CoreMusicLibrary::Adding element Calm Radio Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 27 23:41:06 volumio volumio[931]: Cannot find translation for source Bandcamp Discover Mar 27 23:41:06 volumio volumio[931]: Cannot find translation for source Calm Radio Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 27 23:41:06 volumio volumio[931]: info: Discovery: Getting this device information Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Mar 27 23:41:06 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 27 23:41:06 volumio volumio[931]: info: [1774651266925] CoreMusicLibrary::Adding element Jellyfin Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 27 23:41:06 volumio volumio[931]: Cannot find translation for source Bandcamp Discover Mar 27 23:41:06 volumio volumio[931]: Cannot find translation for source Calm Radio Mar 27 23:41:06 volumio volumio[931]: Cannot find translation for source Jellyfin Mar 27 23:41:06 volumio volumio[931]: info: [jellyfin] Initialized plugin with device info: {"id":"e388eb39-58e3-4fd9-88e6-a66a01b70549","host":"http://192.168.1.161","name":"Volumio","type":"device","serviceName":"Volumio","state":{"status":"stop","volume":63,"mute":false,"track":"1.FM - Sax4Love (www.1.fm)","albumart":"http://192.168.1.161/albumart"}} Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 27 23:41:06 volumio volumio[931]: info: [1774651266953] CoreMusicLibrary::Adding element SoundCloud Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 27 23:41:06 volumio volumio[931]: Cannot find translation for source Bandcamp Discover Mar 27 23:41:06 volumio volumio[931]: Cannot find translation for source Calm Radio Mar 27 23:41:06 volumio volumio[931]: Cannot find translation for source Jellyfin Mar 27 23:41:06 volumio volumio[931]: Cannot find translation for source SoundCloud Mar 27 23:41:06 volumio volumio[931]: info: Checking for old spotify connect plugin installed Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 27 23:41:06 volumio volumio[931]: info: [1774651266991] CoreMusicLibrary::Adding element YouTube Music Mar 27 23:41:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 27 23:41:06 volumio volumio[931]: Cannot find translation for source Bandcamp Discover Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source Calm Radio Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source Jellyfin Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source SoundCloud Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source YouTube Music Mar 27 23:41:07 volumio volumio[931]: info: AutoStart - onStart Mar 27 23:41:07 volumio volumio[931]: info: [now-playing] ConfigUpdater: config is up to date. Mar 27 23:41:07 volumio volumio[931]: info: Loading i18n strings for locale fr Mar 27 23:41:07 volumio volumio[931]: info: Plugin mpdoutput has duplicated i18n key SAVE. It is ignored. Mar 27 23:41:07 volumio volumio[931]: info: Plugin peppymeterbasic has duplicated i18n key APPLY. It is ignored. Mar 27 23:41:07 volumio volumio[931]: info: Plugin peppymeterbasic has duplicated i18n key SAVE. It is ignored. Mar 27 23:41:07 volumio volumio[931]: info: Plugin peppymeterbasic has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. Mar 27 23:41:07 volumio volumio[931]: info: Plugin peppymeterbasic has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. Mar 27 23:41:07 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Mar 27 23:41:07 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:07 volumio volumio[931]: info: FusionDsp - mixtype--------------------- Hardware Mar 27 23:41:07 volumio volumio[931]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 27 23:41:07 volumio volumio[931]: info: [1774651267078] CoreMusicLibrary::Adding element 80s80s Radio Mar 27 23:41:07 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source Bandcamp Discover Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source Calm Radio Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source Jellyfin Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source SoundCloud Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source YouTube Music Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source 80s80s Radio Mar 27 23:41:07 volumio volumio[931]: info: Stopping AccessToken refresher cron for DMD2 Music Mar 27 23:41:07 volumio sudo[1310]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Mar 27 23:41:07 volumio sudo[1310]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:07 volumio volumio[931]: info: AccessToken refresher cron started for DMD2 Music Mar 27 23:41:07 volumio volumio[931]: info: Loading i18n strings for locale fr Mar 27 23:41:07 volumio volumio[931]: info: Plugin mpdoutput has duplicated i18n key SAVE. It is ignored. Mar 27 23:41:07 volumio volumio[931]: info: Plugin peppymeterbasic has duplicated i18n key APPLY. It is ignored. Mar 27 23:41:07 volumio volumio[931]: info: Plugin peppymeterbasic has duplicated i18n key SAVE. It is ignored. Mar 27 23:41:07 volumio volumio[931]: info: Plugin peppymeterbasic has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. Mar 27 23:41:07 volumio volumio[931]: info: Plugin peppymeterbasic has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. Mar 27 23:41:07 volumio sudo[1313]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart logitechmediaserver Mar 27 23:41:07 volumio sudo[1313]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:07 volumio systemd[1]: Started RoonBridge. Mar 27 23:41:07 volumio sudo[1310]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:07 volumio systemd[1]: Stopping Logitech Media Server Daemon... Mar 27 23:41:07 volumio volumio[931]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 27 23:41:07 volumio volumio[931]: info: [1774651267289] CoreMusicLibrary::Adding element Mother Earth Radio Mar 27 23:41:07 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source Bandcamp Discover Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source Calm Radio Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source Jellyfin Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source SoundCloud Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source YouTube Music Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source 80s80s Radio Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source Mother Earth Radio Mar 27 23:41:07 volumio squeezeboxserver[769]: [26-03-27 23:40:28.3525] Slim::Formats::XML::gotErrorViaHTTP (343) Error: getting https://www.mysqueezebox.com/api/sounds/v1/opml Mar 27 23:41:07 volumio squeezeboxserver[769]: Couldn't resolve IP address for: www.mysqueezebox.com Mar 27 23:41:07 volumio squeezeboxserver[769]: [26-03-27 23:40:28.3536] Slim::Plugin::Sounds::Plugin::_gotSoundsError (82) Error: Unable to cache Sounds & Effects menu from SN: Couldn't resolve IP address for: www.mysqueezebox.com Mar 27 23:41:07 volumio squeezeboxserver[769]: [26-03-27 23:40:34.2664] Slim::Plugin::FullTextSearch::Plugin::_initPopularTerms (592) Fulltext index missing or outdated - re-building Mar 27 23:41:07 volumio volumio[931]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 27 23:41:07 volumio volumio[931]: info: [1774651267391] CoreMusicLibrary::Adding element Podcast Mar 27 23:41:07 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source Bandcamp Discover Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source Calm Radio Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source Jellyfin Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source SoundCloud Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source YouTube Music Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source 80s80s Radio Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source Mother Earth Radio Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source Podcast Mar 27 23:41:07 volumio volumio[931]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 27 23:41:07 volumio volumio[931]: info: [1774651267416] CoreMusicLibrary::Adding element Radio Paradise Mar 27 23:41:07 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source Bandcamp Discover Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source Calm Radio Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source Jellyfin Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source SoundCloud Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source YouTube Music Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source 80s80s Radio Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source Mother Earth Radio Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source Podcast Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source Radio Paradise Mar 27 23:41:07 volumio volumio[931]: info: Configuring GPIO pins Mar 27 23:41:07 volumio kernel: export_store: invalid GPIO 4 Mar 27 23:41:07 volumio volumio[931]: error: Plugin audiophonicsonoff failed to start! Error: EINVAL: invalid argument, write Mar 27 23:41:07 volumio volumio[931]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 27 23:41:07 volumio volumio[931]: info: [1774651267431] CoreMusicLibrary::Adding element LastFM Mar 27 23:41:07 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source Bandcamp Discover Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source Calm Radio Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source Jellyfin Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source SoundCloud Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source YouTube Music Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source 80s80s Radio Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source Mother Earth Radio Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source Podcast Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source Radio Paradise Mar 27 23:41:07 volumio volumio[931]: Cannot find translation for source LastFM Mar 27 23:41:07 volumio volumio[931]: info: [LastFM] scrobbler initiated! Mar 27 23:41:07 volumio volumio[931]: info: [LastFM] extended logging: false Mar 27 23:41:07 volumio volumio[931]: info: [LastFM] try scrobble stream/radio plays: true Mar 27 23:41:07 volumio volumio[931]: info: [LastFM] Configuration parameters missing: "API_KEY" "API_SECRET" "username" "authToken" Mar 27 23:41:07 volumio volumio[931]: info: [LastFM] Left init routine Mar 27 23:41:07 volumio volumio[931]: info: [LastFM] Socket already connected: true Mar 27 23:41:07 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Mar 27 23:41:07 volumio volumio[931]: info: Volumio Calling Home Mar 27 23:41:07 volumio systemd[1]: logitechmediaserver.service: Succeeded. Mar 27 23:41:07 volumio systemd[1]: Stopped Logitech Media Server Daemon. Mar 27 23:41:07 volumio systemd[1]: Starting Logitech Media Server Daemon... Mar 27 23:41:07 volumio systemd[1]: Started Logitech Media Server Daemon. Mar 27 23:41:07 volumio sudo[1313]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:07 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 27 23:41:07 volumio volumio[931]: [SpotifyConnect] Creating VLS config file Mar 27 23:41:07 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:07 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:07 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:07 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:07 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:07 volumio volumio[931]: [SpotifyConnect] Starting metadata listener Mar 27 23:41:07 volumio volumio[931]: info: Preparing to generate the ALSA configuration file Mar 27 23:41:07 volumio volumio[931]: info: [LastFM] finished init with error: Configuration parameters missing: "API_KEY" "API_SECRET" "username" "authToken" Mar 27 23:41:07 volumio sudo[1332]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volspotconnect.service Mar 27 23:41:07 volumio sudo[1332]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:07 volumio volumio[931]: info: [now-playing] App is listening on port 4004. Mar 27 23:41:08 volumio volumio[931]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Mar 27 23:41:08 volumio systemd[1]: Started Volspotconnect2 Daemon. Mar 27 23:41:08 volumio sudo[1332]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:08 volumio volumio[931]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Mar 27 23:41:08 volumio volumio[931]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Mar 27 23:41:08 volumio volumio[931]: info: Reading ALSA contributions from plugins. Mar 27 23:41:08 volumio volumio5-onboarding[1283]: time=2026-03-27T23:41:08.138+01:00 level=INFO msg="running volumio5-device-gateway" version=687ad144+CHANGES buildDate=2026-02-10T16:50:24Z Mar 27 23:41:08 volumio volumio[931]: [SpotifyConnect] Vollibrespot Daemon service started! Mar 27 23:41:08 volumio volumio[931]: [Metrics] SpotifyConnect: 0s 589.32ms Mar 27 23:41:08 volumio volumio[931]: info: logitechmediaserver started Mar 27 23:41:08 volumio volumio[931]: info: MPD Permissions set Mar 27 23:41:08 volumio volumio[931]: info: MPD Permissions set Mar 27 23:41:08 volumio volumio[1334]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Mar 27 23:41:08 volumio volumio[1334]: Reading Config from "/tmp/volspotify.toml" Mar 27 23:41:08 volumio volumio[931]: info: Volumio called home Mar 27 23:41:08 volumio volumio[1334]: [Vollibrespot] : Using Alsa backend with device: volumio Mar 27 23:41:08 volumio volumio[931]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Mar 27 23:41:08 volumio volumio[931]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Mar 27 23:41:08 volumio volumio[931]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Mar 27 23:41:08 volumio volumio[931]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 5 Mar 27 23:41:08 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:08 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:08 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:08 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:08 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:08 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:08 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:08 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:08 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 23:41:08 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:08 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:08 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:08 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:08 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:08 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:08 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:08 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:08 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:08 volumio volumio[1334]: [Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Uncategorized, message: "No such device" } Mar 27 23:41:08 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 23:41:08 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:09 volumio volumio[931]: info: camilladsp service started and running in background, instance 1 Mar 27 23:41:09 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:09 volumio volumio[931]: info: FusionDsp - AAAAAAAAAAAAAA-> 44100 48000 88200 96000 176400 192000 384000 <-AAAAAAAAAAAAA Mar 27 23:41:09 volumio volumio[931]: info: FusionDsp loaded Mar 27 23:41:09 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 27 23:41:09 volumio volumio[931]: info: FusionDsp - Reporting Fusion DSP Enabled Mar 27 23:41:09 volumio volumio[931]: info: Adding Signal Path Element [object Object] Mar 27 23:41:09 volumio volumio[931]: info: Adding fusiondspeq DSP Signal Path Element Mar 27 23:41:09 volumio volumio[931]: info: FusionDsp - ---- installed callbackRead Mar 27 23:41:09 volumio volumio[931]: info: FusionDsp - If filter freq >samplerate/2 then disable it Mar 27 23:41:09 volumio volumio[931]: info: FusionDsp - Effects disabled Mar 27 23:41:09 volumio sudo[1375]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Mar 27 23:41:09 volumio sudo[1375]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:09 volumio systemd[1]: Started FusionDsp Daemon. Mar 27 23:41:09 volumio sudo[1375]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:09 volumio volumio[931]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 5 Mar 27 23:41:09 volumio volumio[931]: info: Received Get System Info Mar 27 23:41:09 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 27 23:41:09 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 27 23:41:09 volumio volumio[931]: info: Discovery: Getting this device information Mar 27 23:41:09 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Mar 27 23:41:09 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:09 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 27 23:41:09 volumio volumio5-onboarding[1283]: time=2026-03-27T23:41:09.979+01:00 level=INFO msg="system info for bfabe532d646289d8376bf5d4fab6666" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=3.912 Mar 27 23:41:10 volumio volumio[931]: info: Received Get System Info Mar 27 23:41:10 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 27 23:41:10 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 27 23:41:10 volumio volumio[931]: info: Discovery: Getting this device information Mar 27 23:41:10 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Mar 27 23:41:10 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:10 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 27 23:41:10 volumio volumio[931]: info: Starting Shairport Sync Mar 27 23:41:10 volumio volumio[931]: info: Starting Shairport Sync Mar 27 23:41:10 volumio volumio[931]: info: Starting Shairport Sync Mar 27 23:41:10 volumio sudo[1389]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 27 23:41:10 volumio sudo[1389]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:10 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 27 23:41:10 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 27 23:41:10 volumio sudo[1387]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 27 23:41:10 volumio sudo[1387]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:10 volumio volumio5-onboarding[1283]: time=2026-03-27T23:41:10.187+01:00 level=INFO msg="enabling local network discovery" Mar 27 23:41:10 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Mar 27 23:41:10 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:10 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 27 23:41:10 volumio sudo[1391]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 27 23:41:10 volumio sudo[1391]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:10 volumio systemd[1]: shairport-sync.service: Succeeded. Mar 27 23:41:10 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 27 23:41:10 volumio volumio5-onboarding[1283]: time=2026-03-27T23:41:10.247+01:00 level=INFO msg="enabling BLE discovery" Mar 27 23:41:10 volumio volumio[931]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Mar 27 23:41:10 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 27 23:41:10 volumio sudo[1389]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:10 volumio sudo[1387]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:10 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 27 23:41:10 volumio volumio[931]: info: Asound.conf file unchanged, so no further update is needed Mar 27 23:41:10 volumio volumio[931]: info: Output device has changed, restarting MPD Mar 27 23:41:10 volumio shairport-sync[1398]: free(): double free detected in tcache 2 Mar 27 23:41:10 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=6/ABRT Mar 27 23:41:10 volumio systemd[1]: shairport-sync.service: Failed with result 'signal'. Mar 27 23:41:10 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 27 23:41:10 volumio volumio5-onboarding[1283]: time=2026-03-27T23:41:10.494+01:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 27 23:41:10 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 27 23:41:10 volumio sudo[1391]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:10 volumio volumio[931]: info: Output device has changed, restarting Shairport Sync Mar 27 23:41:10 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:10 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 23:41:10 volumio sudo[1402]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 27 23:41:10 volumio sudo[1402]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:10 volumio sudo[1404]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 27 23:41:10 volumio sudo[1404]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:10 volumio sudo[1402]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:10 volumio volumio[931]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 27 23:41:10 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Mar 27 23:41:10 volumio systemd[1]: mpd.service: Succeeded. Mar 27 23:41:10 volumio systemd[1]: Stopped Music Player Daemon. Mar 27 23:41:10 volumio volumio[931]: [SpotifyConnect] Creating VLS config file Mar 27 23:41:10 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:10 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:10 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:10 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:10 volumio systemd[1]: Starting Music Player Daemon... Mar 27 23:41:10 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:10 volumio volumio[931]: info: Preparing to generate the ALSA configuration file Mar 27 23:41:10 volumio volumio-remote-updater[561]: [2026-03-27 23:41:10] [connect] Successful connection Mar 27 23:41:10 volumio RoonBridge[1314]: 00:00:00.041 Warn: get lock file path: /tmp/.rnbgem0- Mar 27 23:41:10 volumio volumio[931]: [SpotifyConnect] Restarting Vollibrespot Daemon Mar 27 23:41:10 volumio sudo[1412]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 27 23:41:10 volumio sudo[1412]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:10 volumio sudo[1414]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volspotconnect.service Mar 27 23:41:10 volumio sudo[1414]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:11 volumio volumio[931]: info: FusionDsp - {"Reload":{"result":"Ok"}} Mar 27 23:41:11 volumio sudo[1412]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Mar 27 23:41:11 volumio sudo[1412]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:11 volumio volumio[931]: info: Shairport-Sync Started Mar 27 23:41:11 volumio volumio[931]: Error adding Membership: Error: addMembership EINVAL Mar 27 23:41:11 volumio volumio[931]: info: Shairport-Sync Started Mar 27 23:41:11 volumio volumio[931]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Mar 27 23:41:11 volumio volumio[931]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Mar 27 23:41:11 volumio volumio[931]: info: Reading ALSA contributions from plugins. Mar 27 23:41:11 volumio systemd[1]: Stopping Volspotconnect2 Daemon... Mar 27 23:41:11 volumio systemd[1]: volspotconnect.service: Main process exited, code=killed, status=15/TERM Mar 27 23:41:11 volumio systemd[1]: volspotconnect.service: Succeeded. Mar 27 23:41:11 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Mar 27 23:41:11 volumio systemd[1]: Started Volspotconnect2 Daemon. Mar 27 23:41:11 volumio sudo[1414]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:11 volumio volumio[1418]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Mar 27 23:41:11 volumio volumio[1418]: Reading Config from "/tmp/volspotify.toml" Mar 27 23:41:11 volumio volumio[1418]: [Vollibrespot] : Using Alsa backend with device: volumio Mar 27 23:41:11 volumio volumio[931]: info: Received Get System Info Mar 27 23:41:11 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 27 23:41:11 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 27 23:41:11 volumio volumio[931]: info: Discovery: Getting this device information Mar 27 23:41:11 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Mar 27 23:41:11 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:11 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 27 23:41:11 volumio volumio[1418]: [Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Uncategorized, message: "No such device" } Mar 27 23:41:11 volumio volumio[931]: info: MPD Permissions set Mar 27 23:41:11 volumio volumio[931]: info: Shairport-Sync Started Mar 27 23:41:11 volumio volumio-remote-updater[561]: [2026-03-27 23:41:11] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1774651270 101 Mar 27 23:41:11 volumio volumio[931]: 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: 7 Mar 27 23:41:11 volumio volumio[931]: [SpotifyConnect] Vollibrespot Daemon service restarted! Mar 27 23:41:11 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:11 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:11 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:11 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:11 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:11 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:11 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:11 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:11 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 23:41:11 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:11 volumio RoonBridge[1314]: 00:00:01.153 Trace: [childprocess] using unix child process Mar 27 23:41:11 volumio volumio[931]: info: minidlna: Found miniDLNA version 1.2.1 Mar 27 23:41:11 volumio volumio[931]: info: minidlna: Starting minidlna.service Mar 27 23:41:11 volumio volumio[931]: info: Starting Shairport Sync Mar 27 23:41:11 volumio RoonBridge[1314]: 00:00:01.344 Debug: PathForResource, filename: ../.update Mar 27 23:41:11 volumio sudo[1425]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start minidlna.service Mar 27 23:41:11 volumio sudo[1425]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:11 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Mar 27 23:41:11 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:11 volumio volumio[931]: info: CoreCommandRouter::volumioPause Mar 27 23:41:11 volumio volumio[931]: info: CoreStateMachine::pause Mar 27 23:41:11 volumio volumio[931]: info: mpdhttpout --- Volumio set on pause Mar 27 23:41:11 volumio volumio[931]: info: mpdhttpout ---Configuration successfully added to mpd.conf. Mar 27 23:41:11 volumio volumio[931]: info: Asound.conf file unchanged, so no further update is needed Mar 27 23:41:11 volumio volumio[931]: info: Output device has changed, restarting MPD Mar 27 23:41:12 volumio sudo[1429]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 27 23:41:12 volumio sudo[1429]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:12 volumio systemd[1]: Started MiniDLNA lightweight DLNA/UPnP-AV server. Mar 27 23:41:12 volumio volumio[931]: info: Output device has changed, restarting Shairport Sync Mar 27 23:41:12 volumio RoonBridge[1314]: 00:00:01.531 Debug: PathForResource, candidate: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/../.update Mar 27 23:41:12 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:12 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 23:41:12 volumio RoonBridge[1314]: 00:00:01.560 Debug: PathForResource, filename: RAATServer Mar 27 23:41:12 volumio RoonBridge[1314]: 00:00:01.560 Debug: PathForResource, candidate: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RAATServer Mar 27 23:41:12 volumio RoonBridge[1314]: 00:00:01.562 Debug: PathForResource, filename: RoonBridgeHelper Mar 27 23:41:12 volumio RoonBridge[1314]: 00:00:01.562 Debug: PathForResource, candidate: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RoonBridgeHelper Mar 27 23:41:12 volumio sudo[1425]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:12 volumio RoonBridge[1314]: Initializing Mar 27 23:41:12 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 27 23:41:12 volumio sudo[1435]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 27 23:41:12 volumio systemd[1]: shairport-sync.service: Succeeded. Mar 27 23:41:12 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 27 23:41:12 volumio sudo[1433]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 27 23:41:12 volumio sudo[1433]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:12 volumio sudo[1435]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:12 volumio sudo[1429]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:12 volumio RoonBridge[1314]: 00:00:01.760 Info: Starting /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RoonBridgeHelper Mar 27 23:41:12 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 27 23:41:12 volumio sudo[1433]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:12 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Mar 27 23:41:12 volumio systemd[1]: mpd.service: Succeeded. Mar 27 23:41:12 volumio systemd[1]: Stopped Music Player Daemon. Mar 27 23:41:12 volumio volumio[931]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 27 23:41:12 volumio RoonBridge[1314]: 00:00:01.930 Info: ConnectOrStartAndWaitForExit RAATServer, path: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RAATServer Mar 27 23:41:12 volumio volumio[931]: [SpotifyConnect] Creating VLS config file Mar 27 23:41:12 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:12 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:12 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:12 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:12 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:12 volumio systemd[1]: Starting Music Player Daemon... Mar 27 23:41:12 volumio volumio[931]: [SpotifyConnect] Restarting Vollibrespot Daemon Mar 27 23:41:12 volumio volumio[931]: info: Checking Spotify Web API Mar 27 23:41:12 volumio volumio[931]: info: MPD Permissions set Mar 27 23:41:12 volumio volumio[931]: info: Shairport-Sync Started Mar 27 23:41:12 volumio volumio[931]: info: minidlna: systemctl start minidlna.service succeeded. Mar 27 23:41:12 volumio sudo[1454]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volspotconnect.service Mar 27 23:41:12 volumio sudo[1454]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:12 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:12 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:12 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:12 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:12 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:12 volumio systemd[1]: Stopping Volspotconnect2 Daemon... Mar 27 23:41:12 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 23:41:12 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:12 volumio systemd[1]: volspotconnect.service: Main process exited, code=killed, status=15/TERM Mar 27 23:41:12 volumio systemd[1]: volspotconnect.service: Succeeded. Mar 27 23:41:12 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Mar 27 23:41:12 volumio volumio[931]: info: Starting Shairport Sync Mar 27 23:41:12 volumio sudo[1448]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 27 23:41:12 volumio sudo[1448]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:12 volumio systemd[1]: Started Volspotconnect2 Daemon. Mar 27 23:41:12 volumio volumio[931]: info: mpdhttpout ---Configuration successfully replaced in mpd.conf. Mar 27 23:41:12 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Mar 27 23:41:12 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:12 volumio volumio[931]: info: CoreCommandRouter::volumioPause Mar 27 23:41:12 volumio volumio[931]: info: CoreStateMachine::pause Mar 27 23:41:12 volumio volumio[931]: info: mpdhttpout --- Volumio set on pause Mar 27 23:41:12 volumio RoonBridge[1314]: Not Running (.o) Mar 27 23:41:12 volumio sudo[1448]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Mar 27 23:41:12 volumio sudo[1448]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:12 volumio sudo[1472]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 27 23:41:12 volumio sudo[1472]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:12 volumio volumio[1469]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Mar 27 23:41:12 volumio volumio[1469]: Reading Config from "/tmp/volspotify.toml" Mar 27 23:41:12 volumio volumio[1469]: [Vollibrespot] : Using Alsa backend with device: volumio Mar 27 23:41:12 volumio sudo[1454]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:12 volumio volumio[931]: [SpotifyConnect] Vollibrespot Daemon service restarted! Mar 27 23:41:12 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 27 23:41:12 volumio systemd[1]: shairport-sync.service: Succeeded. Mar 27 23:41:12 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 27 23:41:13 volumio volumio[1469]: [Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Uncategorized, message: "No such device" } Mar 27 23:41:13 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 27 23:41:13 volumio sudo[1472]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:13 volumio volumio[931]: info: Shairport-Sync Started Mar 27 23:41:13 volumio RoonBridge[1314]: Running Mar 27 23:41:14 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Mar 27 23:41:14 volumio sudo[1537]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 27 23:41:14 volumio sudo[1537]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:14 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Mar 27 23:41:14 volumio systemd[1]: mpd.service: Succeeded. Mar 27 23:41:14 volumio systemd[1]: Stopped Music Player Daemon. Mar 27 23:41:14 volumio systemd[1]: Starting Music Player Daemon... Mar 27 23:41:14 volumio sudo[1541]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 27 23:41:14 volumio sudo[1541]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:14 volumio sudo[1541]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Mar 27 23:41:14 volumio sudo[1541]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:14 volumio RoonBridge[1314]: 00:00:00.080 Warn: get lock file path: /tmp/.rnbhgem0- Mar 27 23:41:14 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Mar 27 23:41:14 volumio sudo[1546]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 27 23:41:14 volumio sudo[1546]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:15 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Mar 27 23:41:15 volumio systemd[1]: mpd.service: Succeeded. Mar 27 23:41:15 volumio systemd[1]: Stopped Music Player Daemon. Mar 27 23:41:15 volumio systemd[1]: Starting Music Player Daemon... Mar 27 23:41:15 volumio sudo[1549]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 27 23:41:15 volumio sudo[1549]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:15 volumio sudo[1549]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Mar 27 23:41:15 volumio sudo[1549]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:17 volumio volumio[931]: info: Checking Spotify Web API Mar 27 23:41:18 volumio squeezeboxserver[1330]: [26-03-27 23:41:12.7211] main::init (377) Starting Logitech Media Server (v8.3.1, 1676361197, Fri 17 Feb 2023 06:39:27 AM CET) perl 5.028001 - arm-linux-gnueabihf-thread-multi-64int Mar 27 23:41:18 volumio squeezeboxserver[1330]: [26-03-27 23:41:17.8750] Slim::Plugin::FullTextSearch::Plugin::_initPopularTerms (592) Fulltext index missing or outdated - re-building Mar 27 23:41:18 volumio squeezeboxserver[1330]: [26-03-27 23:41:17.8764] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (480) Starting fulltext index build Mar 27 23:41:18 volumio squeezeboxserver[1330]: [26-03-27 23:41:17.8779] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (488) Initialize fulltext table Mar 27 23:41:18 volumio squeezeboxserver[1330]: [26-03-27 23:41:17.8881] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (501) Create fulltext index for tracks Mar 27 23:41:18 volumio squeezeboxserver[1330]: [26-03-27 23:41:17.8919] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (511) Create fulltext index for albums Mar 27 23:41:18 volumio squeezeboxserver[1330]: [26-03-27 23:41:17.8940] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (520) Create fulltext index for contributors Mar 27 23:41:18 volumio squeezeboxserver[1330]: [26-03-27 23:41:17.9009] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (530) Create fulltext index for playlists Mar 27 23:41:18 volumio squeezeboxserver[1330]: [26-03-27 23:41:17.9165] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (545) Optimize fulltext index Mar 27 23:41:18 volumio squeezeboxserver[1330]: [26-03-27 23:41:17.9245] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (560) Fulltext index build done! Mar 27 23:41:18 volumio squeezeboxserver[1330]: [26-03-27 23:41:18.2971] main::checkDataSource (1107) Warning: Schema updated or no media found in the database, initiating scan. Mar 27 23:41:18 volumio mpd[1553]: Mar 27 23:41 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 27 23:41:18 volumio volumio[931]: Upnp client error: Error: This socket has been ended by the other party Mar 27 23:41:18 volumio systemd[1]: Started Music Player Daemon. Mar 27 23:41:18 volumio sudo[1546]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:18 volumio sudo[1435]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:18 volumio sudo[1404]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:18 volumio sudo[1267]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:18 volumio sudo[1537]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:18 volumio sudo[1281]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:18 volumio volumio[931]: error: MPD error: The expression evaluated to a falsy value: Mar 27 23:41:18 volumio volumio[931]: assert.ok(self.idling) Mar 27 23:41:18 volumio volumio[931]: error: The expression evaluated to a falsy value: Mar 27 23:41:18 volumio volumio[931]: assert.ok(self.idling) Mar 27 23:41:18 volumio volumio[931]: info: Checking Spotify Web API Mar 27 23:41:18 volumio volumio[931]: error: MPD error: The expression evaluated to a falsy value: Mar 27 23:41:18 volumio volumio[931]: assert.ok(self.idling) Mar 27 23:41:18 volumio volumio[931]: error: The expression evaluated to a falsy value: Mar 27 23:41:18 volumio volumio[931]: assert.ok(self.idling) Mar 27 23:41:19 volumio volumio[931]: [yt-cast-receiver] Listening on port 8098 Mar 27 23:41:19 volumio volumio[931]: info: Completed starting Core Plugins Mar 27 23:41:19 volumio volumio[931]: info: ------------------------------------------- Mar 27 23:41:19 volumio volumio[931]: info: ----- MyVolumio plugins startup ---- Mar 27 23:41:19 volumio volumio[931]: info: ------------------------------------------- Mar 27 23:41:19 volumio volumio[931]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 27 23:41:19 volumio volumio[931]: error: MPD error: The expression evaluated to a falsy value: Mar 27 23:41:19 volumio volumio[931]: assert.ok(self.idling) Mar 27 23:41:19 volumio volumio[931]: error: The expression evaluated to a falsy value: Mar 27 23:41:19 volumio volumio[931]: assert.ok(self.idling) Mar 27 23:41:19 volumio volumio[931]: error: MPD error: The expression evaluated to a falsy value: Mar 27 23:41:19 volumio volumio[931]: assert.ok(self.idling) Mar 27 23:41:19 volumio volumio[931]: error: The expression evaluated to a falsy value: Mar 27 23:41:19 volumio volumio[931]: assert.ok(self.idling) Mar 27 23:41:19 volumio volumio[931]: error: MPD error: The expression evaluated to a falsy value: Mar 27 23:41:19 volumio volumio[931]: assert.ok(self.idling) Mar 27 23:41:19 volumio volumio[931]: error: The expression evaluated to a falsy value: Mar 27 23:41:19 volumio volumio[931]: assert.ok(self.idling) Mar 27 23:41:19 volumio volumio[931]: info: MPD running with PID1553 Mar 27 23:41:19 volumio volumio[931]: ,establishing connection Mar 27 23:41:19 volumio volumio[931]: error: updateQueue error: null Mar 27 23:41:19 volumio volumio[931]: error: updateQueue error: null Mar 27 23:41:21 volumio squeezeboxserver[1330]: [26-03-27 23:41:21.5856] main::main (202) Starting Logitech Media Server scanner (v8.3.1, 1676361197, Fri 17 Feb 2023 06:39:27 AM CET) perl 5.028001 Mar 27 23:41:21 volumio ntpd[803]: Soliciting pool server 172.232.44.156 Mar 27 23:41:21 volumio ntpd[803]: Soliciting pool server 172.232.63.219 Mar 27 23:41:22 volumio squeezeboxserver[1330]: [26-03-27 23:41:22.7384] Slim::Plugin::Deezer::Importer::isImportEnabled (42) Failed to get Deezer accounts: Can't connect to www.mysqueezebox.com:443 (No address associated with hostname) Mar 27 23:41:22 volumio squeezeboxserver[1330]: [26-03-27 23:41:22.8045] Slim::Music::Import::runImporter (579) Starting Slim::Media::MediaFolderScan scan Mar 27 23:41:22 volumio squeezeboxserver[1330]: [26-03-27 23:41:22.8051] Slim::Music::Import::endImporter (712) Completed Slim::Media::MediaFolderScan Scan in 0.001 seconds. Mar 27 23:41:22 volumio squeezeboxserver[1330]: [26-03-27 23:41:22.8075] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::WiMP::Importer scan Mar 27 23:41:22 volumio squeezeboxserver[1330]: [26-03-27 23:41:22.8353] Slim::Plugin::WiMP::Importer::startScan (44) Failed to get TIDAL accounts: Can't connect to www.mysqueezebox.com:443 (No address associated with hostname) Mar 27 23:41:22 volumio squeezeboxserver[1330]: [26-03-27 23:41:22.8364] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::ExtendedBrowseModes::Libraries scan Mar 27 23:41:22 volumio squeezeboxserver[1330]: [26-03-27 23:41:22.8370] Slim::Music::Import::endImporter (712) Completed Slim::Plugin::ExtendedBrowseModes::Libraries Scan in 0.001 seconds. Mar 27 23:41:22 volumio squeezeboxserver[1330]: [26-03-27 23:41:22.8381] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::FullTextSearch::Plugin scan Mar 27 23:41:22 volumio squeezeboxserver[1330]: [26-03-27 23:41:22.8403] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (480) Starting fulltext index build Mar 27 23:41:22 volumio squeezeboxserver[1330]: [26-03-27 23:41:22.8409] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (488) Initialize fulltext table Mar 27 23:41:22 volumio squeezeboxserver[1330]: [26-03-27 23:41:22.8440] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (501) Create fulltext index for tracks Mar 27 23:41:22 volumio ntpd[803]: Soliciting pool server 162.159.200.1 Mar 27 23:41:22 volumio ntpd[803]: Soliciting pool server 172.233.248.179 Mar 27 23:41:22 volumio squeezeboxserver[1330]: [26-03-27 23:41:22.9517] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (511) Create fulltext index for albums Mar 27 23:41:22 volumio squeezeboxserver[1330]: [26-03-27 23:41:22.9538] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (520) Create fulltext index for contributors Mar 27 23:41:22 volumio squeezeboxserver[1330]: [26-03-27 23:41:22.9556] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (530) Create fulltext index for playlists Mar 27 23:41:22 volumio squeezeboxserver[1330]: [26-03-27 23:41:22.9644] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (545) Optimize fulltext index Mar 27 23:41:22 volumio squeezeboxserver[1330]: [26-03-27 23:41:22.9786] Slim::Plugin::FullTextSearch::Plugin::_rebuildIndex (560) Fulltext index build done! Mar 27 23:41:22 volumio squeezeboxserver[1330]: [26-03-27 23:41:22.9796] Slim::Music::Import::endImporter (712) Completed Slim::Plugin::FullTextSearch::Plugin Scan in 0.141 seconds. Mar 27 23:41:22 volumio squeezeboxserver[1330]: [26-03-27 23:41:22.9808] Slim::Music::Import::runImporter (579) Starting Slim::Plugin::OnlineLibrary::Importer::VirtualLibrariesCleanup scan Mar 27 23:41:22 volumio squeezeboxserver[1330]: [26-03-27 23:41:22.9831] Slim::Music::Import::endImporter (712) Completed Slim::Plugin::OnlineLibrary::Importer::VirtualLibrariesCleanup Scan in 0.002 seconds. Mar 27 23:41:22 volumio squeezeboxserver[1330]: [26-03-27 23:41:22.9859] Slim::Music::Artwork::precacheAllArtwork (657) Starting precacheArtwork for 0 albums Mar 27 23:41:22 volumio squeezeboxserver[1330]: [26-03-27 23:41:22.9865] Slim::Music::Import::endImporter (712) Completed precacheArtwork Scan in 0.002 seconds. Mar 27 23:41:22 volumio squeezeboxserver[1330]: [26-03-27 23:41:22.9878] Slim::Music::Import::runScanPostProcessing (481) Starting Database optimization. Mar 27 23:41:23 volumio squeezeboxserver[1330]: [26-03-27 23:41:23.1827] Slim::Music::Import::endImporter (712) Completed dbOptimize Scan in 0.194 seconds. Mar 27 23:41:23 volumio ntpd[803]: Soliciting pool server 82.66.2.248 Mar 27 23:41:23 volumio ntpd[803]: Soliciting pool server 109.190.177.205 Mar 27 23:41:24 volumio volumio[931]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 27 23:41:24 volumio ntpd[803]: Soliciting pool server 82.64.131.93 Mar 27 23:41:24 volumio ntpd[803]: Soliciting pool server 62.210.129.125 Mar 27 23:41:25 volumio ntpd[803]: Soliciting pool server 92.222.227.225 Mar 27 23:41:25 volumio ntpd[803]: Soliciting pool server 31.58.102.164 Mar 27 23:41:26 volumio volumio[1263]: Generating RSA private key, 4096 bit long modulus (2 primes) Mar 27 23:41:26 volumio ntpd[803]: Soliciting pool server 82.64.230.205 Mar 27 23:41:27 volumio volumio[931]: info: AutoStart - Plugin is starting Mar 27 23:41:27 volumio volumio[931]: info: CoreCommandRouter::volumioGetQueue Mar 27 23:41:27 volumio volumio[931]: info: CoreStateMachine::getQueue Mar 27 23:41:27 volumio volumio[931]: info: CorePlayQueue::getQueue Mar 27 23:41:27 volumio volumio[931]: info: AutoStart - start playing Mar 27 23:41:27 volumio volumio[931]: info: AutoStart - start playing with no specific position Mar 27 23:41:27 volumio volumio[931]: info: CoreCommandRouter::volumioPlay Mar 27 23:41:27 volumio volumio[931]: info: CoreStateMachine::play index 0 Mar 27 23:41:27 volumio volumio[931]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 27 23:41:27 volumio volumio[931]: info: CoreStateMachine::stop Mar 27 23:41:27 volumio volumio[931]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 27 23:41:27 volumio volumio[931]: info: CoreStateMachine::play index undefined Mar 27 23:41:27 volumio volumio[931]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 27 23:41:27 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:27 volumio volumio[931]: info: CoreStateMachine::startPlaybackTimer Mar 27 23:41:27 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:27 volumio volumio[931]: info: [1774651287021] ControllerWebradio::clearAddPlayTrack Mar 27 23:41:27 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand stop Mar 27 23:41:27 volumio volumio[931]: info: sendMpdCommand stop took 2 milliseconds Mar 27 23:41:27 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand clear Mar 27 23:41:27 volumio volumio[931]: info: Mar 27 23:41:27 volumio volumio[931]: ---------------------------- MPD announces system playlist update Mar 27 23:41:27 volumio volumio[931]: info: Ignoring MPD Status Update Mar 27 23:41:27 volumio volumio[931]: info: sendMpdCommand clear took 5 milliseconds Mar 27 23:41:27 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=1420031" Mar 27 23:41:27 volumio volumio[931]: info: Mar 27 23:41:27 volumio volumio[931]: ---------------------------- MPD announces system playlist update Mar 27 23:41:27 volumio volumio[931]: info: Ignoring MPD Status Update Mar 27 23:41:27 volumio volumio[931]: info: Mar 27 23:41:27 volumio volumio[931]: ---------------------------- MPD announces system playlist update Mar 27 23:41:27 volumio volumio[931]: info: Ignoring MPD Status Update Mar 27 23:41:27 volumio volumio[931]: info: Mar 27 23:41:27 volumio volumio[931]: ---------------------------- MPD announces system playlist update Mar 27 23:41:27 volumio volumio[931]: info: Ignoring MPD Status Update Mar 27 23:41:27 volumio volumio[931]: info: Mar 27 23:41:27 volumio volumio[931]: ---------------------------- MPD announces system playlist update Mar 27 23:41:27 volumio volumio[931]: info: Ignoring MPD Status Update Mar 27 23:41:27 volumio volumio[931]: info: Mar 27 23:41:27 volumio volumio[931]: ---------------------------- MPD announces system playlist update Mar 27 23:41:27 volumio volumio[931]: info: Ignoring MPD Status Update Mar 27 23:41:27 volumio volumio[931]: info: Mar 27 23:41:27 volumio volumio[931]: ---------------------------- MPD announces system playlist update Mar 27 23:41:27 volumio volumio[931]: info: Ignoring MPD Status Update Mar 27 23:41:27 volumio volumio[931]: error: updateQueue error: null Mar 27 23:41:27 volumio volumio[931]: info: ------------------------------ 43ms Mar 27 23:41:27 volumio volumio[931]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=1420031" took 231 milliseconds Mar 27 23:41:27 volumio volumio[931]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 27 23:41:27 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand play Mar 27 23:41:27 volumio volumio[931]: info: Mar 27 23:41:27 volumio volumio[931]: ---------------------------- MPD announces system playlist update Mar 27 23:41:27 volumio volumio[931]: info: Ignoring MPD Status Update Mar 27 23:41:27 volumio volumio[931]: info: ------------------------------ 235ms Mar 27 23:41:27 volumio volumio[931]: info: ------------------------------ 231ms Mar 27 23:41:27 volumio volumio[931]: info: ------------------------------ 229ms Mar 27 23:41:27 volumio volumio[931]: info: ------------------------------ 215ms Mar 27 23:41:27 volumio volumio[931]: info: ------------------------------ 211ms Mar 27 23:41:27 volumio volumio[931]: info: ------------------------------ 208ms Mar 27 23:41:27 volumio volumio[931]: info: Mar 27 23:41:27 volumio volumio[931]: ---------------------------- MPD announces system playlist update Mar 27 23:41:27 volumio volumio[931]: info: Ignoring MPD Status Update Mar 27 23:41:27 volumio volumio[931]: info: Mar 27 23:41:27 volumio volumio[931]: ---------------------------- MPD announces system playlist update Mar 27 23:41:27 volumio volumio[931]: info: Ignoring MPD Status Update Mar 27 23:41:27 volumio volumio[931]: info: Mar 27 23:41:27 volumio volumio[931]: ---------------------------- MPD announces system playlist update Mar 27 23:41:27 volumio volumio[931]: info: Ignoring MPD Status Update Mar 27 23:41:27 volumio volumio[931]: info: Mar 27 23:41:27 volumio volumio[931]: ---------------------------- MPD announces system playlist update Mar 27 23:41:27 volumio volumio[931]: info: Ignoring MPD Status Update Mar 27 23:41:27 volumio volumio[931]: info: Mar 27 23:41:27 volumio volumio[931]: ---------------------------- MPD announces system playlist update Mar 27 23:41:27 volumio volumio[931]: info: Ignoring MPD Status Update Mar 27 23:41:27 volumio volumio[931]: info: Mar 27 23:41:27 volumio volumio[931]: ---------------------------- MPD announces system playlist update Mar 27 23:41:27 volumio volumio[931]: info: Ignoring MPD Status Update Mar 27 23:41:27 volumio volumio[931]: info: sendMpdCommand play took 30 milliseconds Mar 27 23:41:27 volumio volumio[931]: info: ------------------------------ 29ms Mar 27 23:41:27 volumio volumio[931]: info: ------------------------------ 23ms Mar 27 23:41:27 volumio volumio[931]: info: ------------------------------ 17ms Mar 27 23:41:27 volumio volumio[931]: info: ------------------------------ 13ms Mar 27 23:41:27 volumio volumio[931]: info: ------------------------------ 10ms Mar 27 23:41:27 volumio volumio[931]: info: ------------------------------ 10ms Mar 27 23:41:27 volumio volumio[931]: info: ------------------------------ 8ms Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 27 23:41:27 volumio volumio[931]: info: Adding plugin bluetooth to MyMusic Plugins Mar 27 23:41:27 volumio volumio[931]: info: Adding plugin multiroom to MyMusic Plugins Mar 27 23:41:27 volumio volumio[931]: info: Adding plugin metavolumio to MyMusic Plugins Mar 27 23:41:27 volumio volumio[931]: info: Adding plugin cd_controller to MyMusic Plugins Mar 27 23:41:27 volumio volumio[931]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 27 23:41:27 volumio volumio[931]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 27 23:41:27 volumio volumio[931]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 27 23:41:27 volumio volumio[931]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 27 23:41:27 volumio ntpd[803]: Soliciting pool server 45.90.162.253 Mar 27 23:41:28 volumio kernel: CIFS: VFS: server 192.168.1.13 of type Samba 3.2.8 returned unexpected error on SMB posix open, disabling posix open support. Check if server update available. Mar 27 23:41:29 volumio ntpd[803]: receive: Unexpected origin timestamp 0xed718618.e60e6c8a does not match aorg 0000000000.00000000 from server@172.233.248.179 xmt 0xed718619.bb52cb36 Mar 27 23:41:29 volumio ntpd[803]: receive: Unexpected origin timestamp 0xed718618.e6017879 does not match aorg 0000000000.00000000 from server@45.90.162.253 xmt 0xed718619.bc99a7c4 Mar 27 23:41:29 volumio ntpd[803]: Soliciting pool server 51.158.147.185 Mar 27 23:41:29 volumio ntpd[803]: receive: Unexpected origin timestamp 0xed718618.e60c5994 does not match aorg 0000000000.00000000 from server@109.190.177.205 xmt 0xed718619.bd31b400 Mar 27 23:41:30 volumio volumio[931]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 27 23:41:30 volumio volumio[931]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 27 23:41:30 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 23:41:30 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 23:41:30 volumio volumio[931]: info: Starting MyVolumio Remote Streaming Endpoints Mar 27 23:41:30 volumio volumio[931]: info: MyVolumio login type: Token Mar 27 23:41:30 volumio volumio[931]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 27 23:41:30 volumio volumio[931]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 27 23:41:30 volumio ntpd[803]: Soliciting pool server 38.242.218.253 Mar 27 23:41:31 volumio ntpd[803]: Soliciting pool server 109.190.177.200 Mar 27 23:41:32 volumio volumio[931]: info: Starting Streaming Service Transparent Proxy Mar 27 23:41:32 volumio volumio[931]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 27 23:41:32 volumio volumio[931]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 27 23:41:32 volumio volumio[931]: info: Streaming services startup Mar 27 23:41:32 volumio volumio[931]: info: Starting Streaming Daemon Mar 27 23:41:32 volumio sudo[1649]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 27 23:41:32 volumio sudo[1649]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:32 volumio volumio[931]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 27 23:41:32 volumio sudo[1649]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:32 volumio volumio[931]: info: Mar 27 23:41:32 volumio volumio[931]: ---------------------------- MPD announces state update: player Mar 27 23:41:32 volumio volumio[931]: info: ControllerMpd::getState Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand status Mar 27 23:41:32 volumio volumio[931]: info: Mar 27 23:41:32 volumio volumio[931]: ---------------------------- MPD announces state update: player Mar 27 23:41:32 volumio volumio[931]: info: ControllerMpd::getState Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand status Mar 27 23:41:32 volumio volumio[931]: info: Mar 27 23:41:32 volumio volumio[931]: ---------------------------- MPD announces state update: player Mar 27 23:41:32 volumio volumio[931]: info: ControllerMpd::getState Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand status Mar 27 23:41:32 volumio volumio[931]: info: Mar 27 23:41:32 volumio volumio[931]: ---------------------------- MPD announces state update: player Mar 27 23:41:32 volumio volumio[931]: info: ControllerMpd::getState Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand status Mar 27 23:41:32 volumio volumio[931]: info: Mar 27 23:41:32 volumio volumio[931]: ---------------------------- MPD announces state update: player Mar 27 23:41:32 volumio volumio[931]: info: ControllerMpd::getState Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand status Mar 27 23:41:32 volumio volumio[931]: info: Mar 27 23:41:32 volumio volumio[931]: ---------------------------- MPD announces state update: player Mar 27 23:41:32 volumio volumio[931]: info: ControllerMpd::getState Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand status Mar 27 23:41:32 volumio volumio[931]: info: Mar 27 23:41:32 volumio volumio[931]: ---------------------------- MPD announces state update: player Mar 27 23:41:32 volumio volumio[931]: info: ControllerMpd::getState Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand status Mar 27 23:41:32 volumio volumio[931]: info: FusionDsp - ---- read samplerate, raw: 96000,S32_LE,2,32 Mar 27 23:41:32 volumio volumio[931]: info: FusionDsp - ---- read samplerate from file: 96000 Mar 27 23:41:32 volumio volumio[931]: info: camilladsp stopping service pid 1357... Mar 27 23:41:32 volumio volumio[931]: info: camilladsp service terminated, instance 1 Mar 27 23:41:32 volumio volumio[931]: info: FusionDsp - If filter freq >samplerate/2 then disable it Mar 27 23:41:32 volumio volumio[931]: info: FusionDsp - Effects disabled Mar 27 23:41:32 volumio volumio[931]: info: camilladsp service started and running in background, instance 1 Mar 27 23:41:32 volumio volumio[931]: error: Cannot start Volumio Streaming Daemon Mar 27 23:41:32 volumio volumio[931]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 27 23:41:32 volumio volumio[931]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 27 23:41:32 volumio volumio[931]: info: Mar 27 23:41:32 volumio volumio[931]: ---------------------------- MPD announces system playlist update Mar 27 23:41:32 volumio volumio[931]: info: Ignoring MPD Status Update Mar 27 23:41:32 volumio volumio[931]: info: Mar 27 23:41:32 volumio volumio[931]: ---------------------------- MPD announces state update: player Mar 27 23:41:32 volumio volumio[931]: info: ControllerMpd::getState Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand status Mar 27 23:41:32 volumio volumio[931]: info: sendMpdCommand status took 124 milliseconds Mar 27 23:41:32 volumio volumio[931]: info: sendMpdCommand status took 123 milliseconds Mar 27 23:41:32 volumio volumio[931]: info: sendMpdCommand status took 120 milliseconds Mar 27 23:41:32 volumio volumio[931]: info: sendMpdCommand status took 119 milliseconds Mar 27 23:41:32 volumio volumio[931]: info: sendMpdCommand status took 118 milliseconds Mar 27 23:41:32 volumio volumio[931]: info: sendMpdCommand status took 115 milliseconds Mar 27 23:41:32 volumio volumio[931]: info: sendMpdCommand status took 113 milliseconds Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::parseState Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::parseState Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::parseState Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::parseState Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::parseState Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::parseState Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::parseState Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 27 23:41:32 volumio volumio[931]: info: Mar 27 23:41:32 volumio volumio[931]: ---------------------------- MPD announces system playlist update Mar 27 23:41:32 volumio volumio[931]: info: Ignoring MPD Status Update Mar 27 23:41:32 volumio volumio[931]: info: Mar 27 23:41:32 volumio volumio[931]: ---------------------------- MPD announces state update: player Mar 27 23:41:32 volumio volumio[931]: info: ControllerMpd::getState Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand status Mar 27 23:41:32 volumio volumio[931]: info: Mar 27 23:41:32 volumio volumio[931]: ---------------------------- MPD announces system playlist update Mar 27 23:41:32 volumio volumio[931]: info: Ignoring MPD Status Update Mar 27 23:41:32 volumio volumio[931]: info: Mar 27 23:41:32 volumio volumio[931]: ---------------------------- MPD announces state update: player Mar 27 23:41:32 volumio volumio[931]: info: ControllerMpd::getState Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand status Mar 27 23:41:32 volumio volumio[931]: info: Mar 27 23:41:32 volumio volumio[931]: ---------------------------- MPD announces system playlist update Mar 27 23:41:32 volumio volumio[931]: info: Ignoring MPD Status Update Mar 27 23:41:32 volumio volumio[931]: info: Mar 27 23:41:32 volumio volumio[931]: ---------------------------- MPD announces state update: player Mar 27 23:41:32 volumio volumio[931]: info: ControllerMpd::getState Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand status Mar 27 23:41:32 volumio volumio[931]: info: Mar 27 23:41:32 volumio volumio[931]: ---------------------------- MPD announces system playlist update Mar 27 23:41:32 volumio volumio[931]: info: Ignoring MPD Status Update Mar 27 23:41:32 volumio volumio[931]: info: Mar 27 23:41:32 volumio volumio[931]: ---------------------------- MPD announces state update: player Mar 27 23:41:32 volumio volumio[931]: info: ControllerMpd::getState Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand status Mar 27 23:41:32 volumio volumio[931]: info: Mar 27 23:41:32 volumio volumio[931]: ---------------------------- MPD announces system playlist update Mar 27 23:41:32 volumio volumio[931]: info: Ignoring MPD Status Update Mar 27 23:41:32 volumio volumio[931]: info: Mar 27 23:41:32 volumio volumio[931]: ---------------------------- MPD announces state update: player Mar 27 23:41:32 volumio volumio[931]: info: ControllerMpd::getState Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand status Mar 27 23:41:32 volumio volumio[931]: info: Mar 27 23:41:32 volumio volumio[931]: ---------------------------- MPD announces system playlist update Mar 27 23:41:32 volumio volumio[931]: info: Ignoring MPD Status Update Mar 27 23:41:32 volumio volumio[931]: info: Mar 27 23:41:32 volumio volumio[931]: ---------------------------- MPD announces state update: player Mar 27 23:41:32 volumio volumio[931]: info: ControllerMpd::getState Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand status Mar 27 23:41:32 volumio volumio[931]: info: ------------------------------ 101ms Mar 27 23:41:32 volumio volumio[931]: info: sendMpdCommand status took 99 milliseconds Mar 27 23:41:32 volumio volumio[931]: info: sendMpdCommand playlistinfo took 89 milliseconds Mar 27 23:41:32 volumio volumio[931]: info: sendMpdCommand playlistinfo took 88 milliseconds Mar 27 23:41:32 volumio volumio[931]: info: sendMpdCommand playlistinfo took 87 milliseconds Mar 27 23:41:32 volumio volumio[931]: info: sendMpdCommand playlistinfo took 86 milliseconds Mar 27 23:41:32 volumio volumio[931]: info: ------------------------------ 84ms Mar 27 23:41:32 volumio volumio[931]: info: sendMpdCommand status took 82 milliseconds Mar 27 23:41:32 volumio volumio[931]: info: ------------------------------ 81ms Mar 27 23:41:32 volumio volumio[931]: info: sendMpdCommand status took 79 milliseconds Mar 27 23:41:32 volumio volumio[931]: info: ------------------------------ 79ms Mar 27 23:41:32 volumio volumio[931]: info: sendMpdCommand status took 77 milliseconds Mar 27 23:41:32 volumio volumio[931]: info: ------------------------------ 78ms Mar 27 23:41:32 volumio volumio[931]: info: sendMpdCommand status took 77 milliseconds Mar 27 23:41:32 volumio volumio[931]: info: ------------------------------ 76ms Mar 27 23:41:32 volumio volumio[931]: info: sendMpdCommand status took 75 milliseconds Mar 27 23:41:32 volumio volumio[931]: info: ------------------------------ 74ms Mar 27 23:41:32 volumio volumio[931]: info: sendMpdCommand status took 73 milliseconds Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::parseState Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::parseTrackInfo Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::parseTrackInfo Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::parseTrackInfo Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::parseTrackInfo Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::parseTrackInfo Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::parseState Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::parseState Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::parseState Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::parseState Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::parseState Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::parseState Mar 27 23:41:32 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 27 23:41:32 volumio volumio[931]: info: ControllerMpd::pushState Mar 27 23:41:32 volumio volumio[931]: info: CoreCommandRouter::servicePushState Mar 27 23:41:32 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:32 volumio volumio[931]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2759,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Brian Culbertson - On My Mind","artist":"1.FM - Sax4Ever","album":null,"uri":"http://185.33.21.112:80/sax4ever_128","trackType":""} Mar 27 23:41:32 volumio volumio[931]: verbose: CURRENT POSITION 0 Mar 27 23:41:32 volumio volumio[931]: info: CoreStateMachine::syncState stateService play Mar 27 23:41:32 volumio volumio[931]: info: CoreStateMachine::syncState currentStatus stop Mar 27 23:41:32 volumio volumio[931]: info: ControllerMpd::pushState Mar 27 23:41:32 volumio volumio[931]: info: CoreCommandRouter::servicePushState Mar 27 23:41:32 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:32 volumio volumio[931]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2759,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Brian Culbertson - On My Mind","artist":"1.FM - Sax4Ever","album":null,"uri":"http://185.33.21.112:80/sax4ever_128","trackType":""} Mar 27 23:41:32 volumio volumio[931]: verbose: CURRENT POSITION 0 Mar 27 23:41:32 volumio volumio[931]: info: CoreStateMachine::syncState stateService play Mar 27 23:41:32 volumio volumio[931]: info: CoreStateMachine::syncState currentStatus play Mar 27 23:41:32 volumio volumio[931]: info: Received an update from plugin. extracting info from payload Mar 27 23:41:32 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Mar 27 23:41:32 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:32 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 27 23:41:32 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:32 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:32 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:32 volumio volumio[931]: info: ControllerMpd::pushState Mar 27 23:41:32 volumio volumio[931]: info: CoreCommandRouter::servicePushState Mar 27 23:41:32 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:32 volumio volumio[931]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2759,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Brian Culbertson - On My Mind","artist":"1.FM - Sax4Ever","album":null,"uri":"http://185.33.21.112:80/sax4ever_128","trackType":""} Mar 27 23:41:32 volumio volumio[931]: verbose: CURRENT POSITION 0 Mar 27 23:41:32 volumio volumio[931]: info: CoreStateMachine::syncState stateService play Mar 27 23:41:32 volumio volumio[931]: info: CoreStateMachine::syncState currentStatus play Mar 27 23:41:32 volumio volumio[931]: info: Received an update from plugin. extracting info from payload Mar 27 23:41:32 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Mar 27 23:41:32 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:32 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:32 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:32 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:32 volumio volumio[931]: info: ControllerMpd::pushState Mar 27 23:41:32 volumio volumio[931]: info: CoreCommandRouter::servicePushState Mar 27 23:41:32 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:32 volumio volumio[931]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2759,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Brian Culbertson - On My Mind","artist":"1.FM - Sax4Ever","album":null,"uri":"http://185.33.21.112:80/sax4ever_128","trackType":""} Mar 27 23:41:32 volumio volumio[931]: verbose: CURRENT POSITION 0 Mar 27 23:41:32 volumio volumio[931]: info: CoreStateMachine::syncState stateService play Mar 27 23:41:32 volumio volumio[931]: info: CoreStateMachine::syncState currentStatus play Mar 27 23:41:32 volumio volumio[931]: info: Received an update from plugin. extracting info from payload Mar 27 23:41:32 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Mar 27 23:41:32 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:32 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:32 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:32 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:32 volumio volumio[931]: info: ControllerMpd::pushState Mar 27 23:41:32 volumio volumio[931]: info: CoreCommandRouter::servicePushState Mar 27 23:41:32 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:32 volumio volumio[931]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2759,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Brian Culbertson - On My Mind","artist":"1.FM - Sax4Ever","album":null,"uri":"http://185.33.21.112:80/sax4ever_128","trackType":""} Mar 27 23:41:32 volumio volumio[931]: verbose: CURRENT POSITION 0 Mar 27 23:41:32 volumio volumio[931]: info: CoreStateMachine::syncState stateService play Mar 27 23:41:32 volumio volumio[931]: info: CoreStateMachine::syncState currentStatus play Mar 27 23:41:32 volumio volumio[931]: info: Received an update from plugin. extracting info from payload Mar 27 23:41:32 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Mar 27 23:41:32 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:32 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:32 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:32 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:32 volumio volumio[931]: info: ControllerMpd::pushState Mar 27 23:41:32 volumio volumio[931]: info: CoreCommandRouter::servicePushState Mar 27 23:41:32 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:32 volumio volumio[931]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2759,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Brian Culbertson - On My Mind","artist":"1.FM - Sax4Ever","album":null,"uri":"http://185.33.21.112:80/sax4ever_128","trackType":""} Mar 27 23:41:32 volumio volumio[931]: verbose: CURRENT POSITION 0 Mar 27 23:41:32 volumio volumio[931]: info: CoreStateMachine::syncState stateService play Mar 27 23:41:32 volumio volumio[931]: info: CoreStateMachine::syncState currentStatus play Mar 27 23:41:32 volumio volumio[931]: info: Received an update from plugin. extracting info from payload Mar 27 23:41:32 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Mar 27 23:41:32 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:32 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:32 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:32 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:32 volumio volumio[931]: info: ControllerMpd::pushState Mar 27 23:41:32 volumio volumio[931]: info: CoreCommandRouter::servicePushState Mar 27 23:41:32 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:32 volumio volumio[931]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2759,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Brian Culbertson - On My Mind","artist":"1.FM - Sax4Ever","album":null,"uri":"http://185.33.21.112:80/sax4ever_128","trackType":""} Mar 27 23:41:32 volumio volumio[931]: verbose: CURRENT POSITION 0 Mar 27 23:41:32 volumio volumio[931]: info: CoreStateMachine::syncState stateService play Mar 27 23:41:32 volumio volumio[931]: info: CoreStateMachine::syncState currentStatus play Mar 27 23:41:32 volumio volumio[931]: info: Received an update from plugin. extracting info from payload Mar 27 23:41:32 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Mar 27 23:41:32 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:32 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:32 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:32 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:32 volumio volumio[931]: info: ------------------------------ 335ms Mar 27 23:41:32 volumio volumio[931]: info: ------------------------------ 528ms Mar 27 23:41:32 volumio volumio[931]: info: ------------------------------ 528ms Mar 27 23:41:32 volumio volumio[931]: info: ------------------------------ 527ms Mar 27 23:41:32 volumio volumio[931]: info: ------------------------------ 534ms Mar 27 23:41:32 volumio volumio[931]: info: ------------------------------ 534ms Mar 27 23:41:32 volumio volumio[931]: info: ------------------------------ 532ms Mar 27 23:41:32 volumio volumio[931]: info: sendMpdCommand playlistinfo took 359 milliseconds Mar 27 23:41:32 volumio volumio[931]: info: sendMpdCommand playlistinfo took 350 milliseconds Mar 27 23:41:32 volumio volumio[931]: info: sendMpdCommand playlistinfo took 348 milliseconds Mar 27 23:41:32 volumio volumio[931]: info: sendMpdCommand playlistinfo took 348 milliseconds Mar 27 23:41:32 volumio volumio[931]: info: sendMpdCommand playlistinfo took 348 milliseconds Mar 27 23:41:33 volumio volumio[931]: info: sendMpdCommand playlistinfo took 349 milliseconds Mar 27 23:41:33 volumio volumio[931]: info: sendMpdCommand playlistinfo took 351 milliseconds Mar 27 23:41:33 volumio volumio[931]: verbose: ControllerMpd::parseTrackInfo Mar 27 23:41:33 volumio volumio[931]: verbose: ControllerMpd::parseTrackInfo Mar 27 23:41:33 volumio volumio[931]: verbose: ControllerMpd::parseTrackInfo Mar 27 23:41:33 volumio volumio[931]: verbose: ControllerMpd::parseTrackInfo Mar 27 23:41:33 volumio volumio[931]: verbose: ControllerMpd::parseTrackInfo Mar 27 23:41:33 volumio volumio[931]: verbose: ControllerMpd::parseTrackInfo Mar 27 23:41:33 volumio volumio[931]: verbose: ControllerMpd::parseTrackInfo Mar 27 23:41:33 volumio volumio[931]: info: ControllerMpd::pushState Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::servicePushState Mar 27 23:41:33 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:33 volumio volumio[931]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2759,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Brian Culbertson - On My Mind","artist":"1.FM - Sax4Ever","album":null,"uri":"http://185.33.21.112:80/sax4ever_128","trackType":""} Mar 27 23:41:33 volumio volumio[931]: verbose: CURRENT POSITION 0 Mar 27 23:41:33 volumio volumio[931]: info: CoreStateMachine::syncState stateService play Mar 27 23:41:33 volumio volumio[931]: info: CoreStateMachine::syncState currentStatus play Mar 27 23:41:33 volumio volumio[931]: info: Received an update from plugin. extracting info from payload Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Mar 27 23:41:33 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:33 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:33 volumio volumio[931]: info: ControllerMpd::pushState Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::servicePushState Mar 27 23:41:33 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:33 volumio volumio[931]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2759,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Brian Culbertson - On My Mind","artist":"1.FM - Sax4Ever","album":null,"uri":"http://185.33.21.112:80/sax4ever_128","trackType":""} Mar 27 23:41:33 volumio volumio[931]: verbose: CURRENT POSITION 0 Mar 27 23:41:33 volumio volumio[931]: info: CoreStateMachine::syncState stateService play Mar 27 23:41:33 volumio volumio[931]: info: CoreStateMachine::syncState currentStatus play Mar 27 23:41:33 volumio volumio[931]: info: Received an update from plugin. extracting info from payload Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Mar 27 23:41:33 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:33 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:33 volumio volumio[931]: info: ControllerMpd::pushState Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::servicePushState Mar 27 23:41:33 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:33 volumio volumio[931]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2759,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Brian Culbertson - On My Mind","artist":"1.FM - Sax4Ever","album":null,"uri":"http://185.33.21.112:80/sax4ever_128","trackType":""} Mar 27 23:41:33 volumio volumio[931]: verbose: CURRENT POSITION 0 Mar 27 23:41:33 volumio volumio[931]: info: CoreStateMachine::syncState stateService play Mar 27 23:41:33 volumio volumio[931]: info: CoreStateMachine::syncState currentStatus play Mar 27 23:41:33 volumio volumio[931]: info: Received an update from plugin. extracting info from payload Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Mar 27 23:41:33 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:33 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:33 volumio volumio[931]: info: ControllerMpd::pushState Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::servicePushState Mar 27 23:41:33 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:33 volumio volumio[931]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2759,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Brian Culbertson - On My Mind","artist":"1.FM - Sax4Ever","album":null,"uri":"http://185.33.21.112:80/sax4ever_128","trackType":""} Mar 27 23:41:33 volumio volumio[931]: verbose: CURRENT POSITION 0 Mar 27 23:41:33 volumio volumio[931]: info: CoreStateMachine::syncState stateService play Mar 27 23:41:33 volumio volumio[931]: info: CoreStateMachine::syncState currentStatus play Mar 27 23:41:33 volumio volumio[931]: info: Received an update from plugin. extracting info from payload Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Mar 27 23:41:33 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:33 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:33 volumio volumio[931]: info: ControllerMpd::pushState Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::servicePushState Mar 27 23:41:33 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:33 volumio volumio[931]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2759,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Brian Culbertson - On My Mind","artist":"1.FM - Sax4Ever","album":null,"uri":"http://185.33.21.112:80/sax4ever_128","trackType":""} Mar 27 23:41:33 volumio volumio[931]: verbose: CURRENT POSITION 0 Mar 27 23:41:33 volumio volumio[931]: info: CoreStateMachine::syncState stateService play Mar 27 23:41:33 volumio volumio[931]: info: CoreStateMachine::syncState currentStatus play Mar 27 23:41:33 volumio volumio[931]: info: Received an update from plugin. extracting info from payload Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Mar 27 23:41:33 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:33 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:33 volumio volumio[931]: info: ControllerMpd::pushState Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::servicePushState Mar 27 23:41:33 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:33 volumio volumio[931]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2759,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Brian Culbertson - On My Mind","artist":"1.FM - Sax4Ever","album":null,"uri":"http://185.33.21.112:80/sax4ever_128","trackType":""} Mar 27 23:41:33 volumio volumio[931]: verbose: CURRENT POSITION 0 Mar 27 23:41:33 volumio volumio[931]: info: CoreStateMachine::syncState stateService play Mar 27 23:41:33 volumio volumio[931]: info: CoreStateMachine::syncState currentStatus play Mar 27 23:41:33 volumio volumio[931]: info: Received an update from plugin. extracting info from payload Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Mar 27 23:41:33 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:33 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:33 volumio volumio[931]: info: ControllerMpd::pushState Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::servicePushState Mar 27 23:41:33 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:33 volumio volumio[931]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2759,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Brian Culbertson - On My Mind","artist":"1.FM - Sax4Ever","album":null,"uri":"http://185.33.21.112:80/sax4ever_128","trackType":""} Mar 27 23:41:33 volumio volumio[931]: verbose: CURRENT POSITION 0 Mar 27 23:41:33 volumio volumio[931]: info: CoreStateMachine::syncState stateService play Mar 27 23:41:33 volumio volumio[931]: info: CoreStateMachine::syncState currentStatus play Mar 27 23:41:33 volumio volumio[931]: info: Received an update from plugin. extracting info from payload Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Mar 27 23:41:33 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:33 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:33 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:33 volumio volumio[931]: info: ------------------------------ 754ms Mar 27 23:41:33 volumio volumio[931]: info: ------------------------------ 734ms Mar 27 23:41:33 volumio volumio[931]: info: ------------------------------ 732ms Mar 27 23:41:33 volumio volumio[931]: info: ------------------------------ 730ms Mar 27 23:41:33 volumio volumio[931]: info: ------------------------------ 729ms Mar 27 23:41:33 volumio volumio[931]: info: ------------------------------ 727ms Mar 27 23:41:33 volumio volumio[931]: info: ------------------------------ 725ms Mar 27 23:41:33 volumio volumio[931]: info: [LastFM] Split composite title into artist: Brian Culbertson and title: On My Mind Mar 27 23:41:33 volumio volumio[931]: error: [LastFM] plugin is not authenticated, please retry, or track info could not be determined (very rare) Mar 27 23:41:33 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 27 23:41:33 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 27 23:41:33 volumio sudo[1667]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 27 23:41:33 volumio sudo[1667]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:33 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 27 23:41:33 volumio sudo[1670]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 27 23:41:33 volumio sudo[1670]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:33 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 27 23:41:33 volumio systemd[1]: Started peppymeterbasic Daemon. Mar 27 23:41:33 volumio sudo[1674]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 27 23:41:33 volumio sudo[1674]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:33 volumio sudo[1667]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:33 volumio sudo[1670]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:33 volumio sudo[1674]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:33 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 27 23:41:33 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 27 23:41:33 volumio sudo[1678]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 27 23:41:33 volumio sudo[1678]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:33 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 27 23:41:33 volumio sudo[1680]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 27 23:41:33 volumio sudo[1680]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:33 volumio volumio[1673]: Traceback (most recent call last): Mar 27 23:41:33 volumio volumio[1673]: File "peppymeter.py", line 18, in Mar 27 23:41:33 volumio volumio[1673]: import pygame Mar 27 23:41:33 volumio volumio[1673]: ModuleNotFoundError: No module named 'pygame' Mar 27 23:41:33 volumio sudo[1678]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:33 volumio systemd[1]: peppymeterbasic.service: Main process exited, code=exited, status=1/FAILURE Mar 27 23:41:33 volumio systemd[1]: peppymeterbasic.service: Failed with result 'exit-code'. Mar 27 23:41:33 volumio sudo[1684]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 27 23:41:33 volumio sudo[1684]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:33 volumio systemd[1]: Started peppymeterbasic Daemon. Mar 27 23:41:33 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 27 23:41:33 volumio sudo[1680]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:33 volumio sudo[1684]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:33 volumio sudo[1688]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 27 23:41:33 volumio sudo[1688]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:33 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 27 23:41:34 volumio sudo[1688]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:34 volumio sudo[1692]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 27 23:41:34 volumio sudo[1692]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:34 volumio sudo[1692]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:34 volumio volumio[1685]: Traceback (most recent call last): Mar 27 23:41:34 volumio volumio[1685]: File "peppymeter.py", line 18, in Mar 27 23:41:34 volumio volumio[1685]: import pygame Mar 27 23:41:34 volumio volumio[1685]: ModuleNotFoundError: No module named 'pygame' Mar 27 23:41:34 volumio systemd[1]: peppymeterbasic.service: Main process exited, code=exited, status=1/FAILURE Mar 27 23:41:34 volumio systemd[1]: peppymeterbasic.service: Failed with result 'exit-code'. Mar 27 23:41:34 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 27 23:41:34 volumio sudo[1695]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 27 23:41:34 volumio sudo[1695]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:34 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 27 23:41:34 volumio sudo[1699]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 27 23:41:34 volumio sudo[1699]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:34 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 27 23:41:34 volumio systemd[1]: Started peppymeterbasic Daemon. Mar 27 23:41:34 volumio sudo[1701]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 27 23:41:34 volumio sudo[1695]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:34 volumio sudo[1701]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:34 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 27 23:41:34 volumio sudo[1701]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:34 volumio volumio[1698]: Traceback (most recent call last): Mar 27 23:41:34 volumio volumio[1698]: File "peppymeter.py", line 18, in Mar 27 23:41:34 volumio volumio[1698]: import pygame Mar 27 23:41:34 volumio volumio[1698]: ModuleNotFoundError: No module named 'pygame' Mar 27 23:41:34 volumio systemd[1]: peppymeterbasic.service: Main process exited, code=exited, status=1/FAILURE Mar 27 23:41:34 volumio systemd[1]: peppymeterbasic.service: Failed with result 'exit-code'. Mar 27 23:41:34 volumio sudo[1699]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:34 volumio sudo[1706]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 27 23:41:34 volumio sudo[1706]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:34 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 27 23:41:34 volumio volumio[931]: STREAMING PROXY: Starting server on port 3245 Mar 27 23:41:34 volumio volumio[931]: Node JS runtime: 14 Mar 27 23:41:34 volumio sudo[1709]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 27 23:41:34 volumio sudo[1709]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:34 volumio systemd[1]: Started peppymeterbasic Daemon. Mar 27 23:41:34 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 27 23:41:34 volumio sudo[1713]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 27 23:41:34 volumio sudo[1713]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:34 volumio sudo[1706]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:34 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 27 23:41:34 volumio sudo[1709]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:34 volumio volumio[1711]: Traceback (most recent call last): Mar 27 23:41:34 volumio volumio[1711]: File "peppymeter.py", line 18, in Mar 27 23:41:34 volumio volumio[1711]: import pygame Mar 27 23:41:34 volumio volumio[1711]: ModuleNotFoundError: No module named 'pygame' Mar 27 23:41:34 volumio sudo[1713]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:34 volumio systemd[1]: peppymeterbasic.service: Main process exited, code=exited, status=1/FAILURE Mar 27 23:41:34 volumio systemd[1]: peppymeterbasic.service: Failed with result 'exit-code'. Mar 27 23:41:34 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 27 23:41:34 volumio sudo[1717]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 27 23:41:34 volumio sudo[1717]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:34 volumio sudo[1719]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 27 23:41:34 volumio sudo[1719]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:34 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 27 23:41:35 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 27 23:41:35 volumio sudo[1724]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 27 23:41:35 volumio sudo[1724]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:35 volumio systemd[1]: Started peppymeterbasic Daemon. Mar 27 23:41:35 volumio sudo[1717]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:35 volumio sudo[1726]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 27 23:41:35 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 27 23:41:35 volumio sudo[1726]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:35 volumio sudo[1719]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:35 volumio sudo[1724]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:35 volumio sudo[1726]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:35 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 27 23:41:35 volumio sudo[1731]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 27 23:41:35 volumio sudo[1731]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:35 volumio volumio[1723]: Traceback (most recent call last): Mar 27 23:41:35 volumio volumio[1723]: File "peppymeter.py", line 18, in Mar 27 23:41:35 volumio volumio[1723]: import pygame Mar 27 23:41:35 volumio volumio[1723]: ModuleNotFoundError: No module named 'pygame' Mar 27 23:41:35 volumio systemd[1]: peppymeterbasic.service: Main process exited, code=exited, status=1/FAILURE Mar 27 23:41:35 volumio systemd[1]: peppymeterbasic.service: Failed with result 'exit-code'. Mar 27 23:41:35 volumio systemd[1]: peppymeterbasic.service: Start request repeated too quickly. Mar 27 23:41:35 volumio systemd[1]: peppymeterbasic.service: Failed with result 'exit-code'. Mar 27 23:41:35 volumio systemd[1]: Failed to start peppymeterbasic Daemon. Mar 27 23:41:35 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 27 23:41:35 volumio sudo[1731]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:35 volumio sudo[1733]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 27 23:41:35 volumio sudo[1733]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:35 volumio systemd[1]: peppymeterbasic.service: Start request repeated too quickly. Mar 27 23:41:35 volumio systemd[1]: peppymeterbasic.service: Failed with result 'exit-code'. Mar 27 23:41:35 volumio systemd[1]: Failed to start peppymeterbasic Daemon. Mar 27 23:41:35 volumio sudo[1733]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:35 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 27 23:41:35 volumio sudo[1736]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 27 23:41:35 volumio sudo[1736]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:35 volumio sudo[1739]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 27 23:41:35 volumio sudo[1739]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:35 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 27 23:41:35 volumio systemd[1]: peppymeterbasic.service: Start request repeated too quickly. Mar 27 23:41:35 volumio systemd[1]: peppymeterbasic.service: Failed with result 'exit-code'. Mar 27 23:41:35 volumio systemd[1]: Failed to start peppymeterbasic Daemon. Mar 27 23:41:35 volumio sudo[1736]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:35 volumio systemd[1]: peppymeterbasic.service: Start request repeated too quickly. Mar 27 23:41:35 volumio systemd[1]: peppymeterbasic.service: Failed with result 'exit-code'. Mar 27 23:41:35 volumio systemd[1]: Failed to start peppymeterbasic Daemon. Mar 27 23:41:35 volumio sudo[1739]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:35 volumio sudo[1743]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 27 23:41:35 volumio sudo[1743]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:35 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 27 23:41:35 volumio systemd[1]: peppymeterbasic.service: Start request repeated too quickly. Mar 27 23:41:35 volumio systemd[1]: peppymeterbasic.service: Failed with result 'exit-code'. Mar 27 23:41:35 volumio systemd[1]: Failed to start peppymeterbasic Daemon. Mar 27 23:41:35 volumio sudo[1743]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:35 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status play Mar 27 23:41:35 volumio sudo[1746]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 27 23:41:35 volumio sudo[1746]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:35 volumio sudo[1748]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 27 23:41:35 volumio sudo[1748]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:35 volumio systemd[1]: peppymeterbasic.service: Start request repeated too quickly. Mar 27 23:41:35 volumio systemd[1]: peppymeterbasic.service: Failed with result 'exit-code'. Mar 27 23:41:35 volumio systemd[1]: Failed to start peppymeterbasic Daemon. Mar 27 23:41:35 volumio systemd[1]: peppymeterbasic.service: Start request repeated too quickly. Mar 27 23:41:35 volumio systemd[1]: peppymeterbasic.service: Failed with result 'exit-code'. Mar 27 23:41:35 volumio systemd[1]: Failed to start peppymeterbasic Daemon. Mar 27 23:41:35 volumio sudo[1746]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:35 volumio sudo[1748]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:35 volumio sudo[1752]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Mar 27 23:41:35 volumio sudo[1752]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:35 volumio systemd[1]: peppymeterbasic.service: Start request repeated too quickly. Mar 27 23:41:35 volumio systemd[1]: peppymeterbasic.service: Failed with result 'exit-code'. Mar 27 23:41:35 volumio systemd[1]: Failed to start peppymeterbasic Daemon. Mar 27 23:41:35 volumio sudo[1752]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:35 volumio volumio[931]: error: MyVolumio Custom Token format not valid, refreshing it Mar 27 23:41:35 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic failed to start. Check your configuration Error: Command failed: /usr/bin/sudo /bin/systemctl start peppymeterbasic.service Mar 27 23:41:35 volumio volumio[931]: Job for peppymeterbasic.service failed because the control process exited with error code. Mar 27 23:41:35 volumio volumio[931]: See "systemctl status peppymeterbasic.service" and "journalctl -xe" for details. Mar 27 23:41:35 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic failed to start. Check your configuration Error: Command failed: /usr/bin/sudo /bin/systemctl start peppymeterbasic.service Mar 27 23:41:35 volumio volumio[931]: Job for peppymeterbasic.service failed because the control process exited with error code. Mar 27 23:41:35 volumio volumio[931]: See "systemctl status peppymeterbasic.service" and "journalctl -xe" for details. Mar 27 23:41:35 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic failed to start. Check your configuration Error: Command failed: /usr/bin/sudo /bin/systemctl start peppymeterbasic.service Mar 27 23:41:35 volumio volumio[931]: Job for peppymeterbasic.service failed because the control process exited with error code. Mar 27 23:41:35 volumio volumio[931]: See "systemctl status peppymeterbasic.service" and "journalctl -xe" for details. Mar 27 23:41:35 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic failed to start. Check your configuration Error: Command failed: /usr/bin/sudo /bin/systemctl start peppymeterbasic.service Mar 27 23:41:35 volumio volumio[931]: Job for peppymeterbasic.service failed because the control process exited with error code. Mar 27 23:41:35 volumio volumio[931]: See "systemctl status peppymeterbasic.service" and "journalctl -xe" for details. Mar 27 23:41:35 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic failed to start. Check your configuration Error: Command failed: /usr/bin/sudo /bin/systemctl start peppymeterbasic.service Mar 27 23:41:35 volumio volumio[931]: Job for peppymeterbasic.service failed because the control process exited with error code. Mar 27 23:41:35 volumio volumio[931]: See "systemctl status peppymeterbasic.service" and "journalctl -xe" for details. Mar 27 23:41:35 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic failed to start. Check your configuration Error: Command failed: /usr/bin/sudo /bin/systemctl start peppymeterbasic.service Mar 27 23:41:35 volumio volumio[931]: Job for peppymeterbasic.service failed because the control process exited with error code. Mar 27 23:41:35 volumio volumio[931]: See "systemctl status peppymeterbasic.service" and "journalctl -xe" for details. Mar 27 23:41:35 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic failed to start. Check your configuration Error: Command failed: /usr/bin/sudo /bin/systemctl start peppymeterbasic.service Mar 27 23:41:35 volumio volumio[931]: Job for peppymeterbasic.service failed because the control process exited with error code. Mar 27 23:41:35 volumio volumio[931]: See "systemctl status peppymeterbasic.service" and "journalctl -xe" for details. Mar 27 23:41:35 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic failed to start. Check your configuration Error: Command failed: /usr/bin/sudo /bin/systemctl start peppymeterbasic.service Mar 27 23:41:35 volumio volumio[931]: Job for peppymeterbasic.service failed because the control process exited with error code. Mar 27 23:41:35 volumio volumio[931]: See "systemctl status peppymeterbasic.service" and "journalctl -xe" for details. Mar 27 23:41:35 volumio volumio[931]: info: peppymeterbasic Daemon Started Mar 27 23:41:35 volumio volumio[931]: info: peppymeterbasic Daemon Started Mar 27 23:41:35 volumio volumio[931]: info: peppymeterbasic Daemon Started Mar 27 23:41:35 volumio volumio[931]: info: peppymeterbasic Daemon Started Mar 27 23:41:36 volumio volumio[931]: info: MyVolumio login type: Token Mar 27 23:41:37 volumio volumio[931]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 27 23:41:37 volumio kernel: hwmon hwmon1: Undervoltage detected! Mar 27 23:41:38 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 27 23:41:38 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 23:41:38 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 27 23:41:38 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Mar 27 23:41:38 volumio volumio[931]: info: MyVolumio token set successfully Mar 27 23:41:38 volumio volumio[931]: info: MYVOLUMIO: Adding device Mar 27 23:41:38 volumio volumio[931]: info: MYVOLUMIO: Evaluating Server Mar 27 23:41:38 volumio volumio-remote-updater[561]: No test mode Mar 27 23:41:38 volumio volumio-remote-updater[561]: No alpha test mode Mar 27 23:41:40 volumio volumio[931]: info: MyVolumio status changed Mar 27 23:41:40 volumio volumio[931]: info: Streaming services startup Mar 27 23:41:40 volumio volumio[931]: info: Starting Streaming Daemon Mar 27 23:41:40 volumio volumio[931]: info: Removing browser output: myVolumio user plan is not superstar Mar 27 23:41:40 volumio volumio[931]: info: Removing audio output: Mar 27 23:41:40 volumio volumio[931]: info: Stoppping Tunnel 1 Mar 27 23:41:40 volumio volumio[931]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 27 23:41:40 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 27 23:41:40 volumio sudo[1801]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 27 23:41:40 volumio sudo[1801]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:40 volumio sudo[1803]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Mar 27 23:41:40 volumio sudo[1803]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:41:40 volumio volumio[931]: info: Setting Geolocation for MyVolumio to eu6 Mar 27 23:41:40 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 23:41:40 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 27 23:41:40 volumio sudo[1801]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:40 volumio sudo[1803]: pam_unix(sudo:session): session closed for user root Mar 27 23:41:40 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 27 23:41:40 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 27 23:41:40 volumio volumio[931]: info: Remote SSH Stopped Mar 27 23:41:40 volumio volumio[931]: error: Cannot start Volumio Streaming Daemon Mar 27 23:41:40 volumio volumio[931]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 27 23:41:40 volumio volumio[931]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 27 23:41:41 volumio volumio[931]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Mar 27 23:41:41 volumio volumio5-onboarding[1283]: failed to bootstrap state: failed to get music providers: could not get available plugins: could not get available plugins: context deadline exceeded Mar 27 23:41:41 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 27 23:41:41 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 27 23:41:41 volumio volumio[931]: info: Updating MyVolumio device info Mar 27 23:41:41 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 23:41:41 volumio systemd[1]: volumio5-onboarding.service: Service RestartSec=100ms expired, scheduling restart. Mar 27 23:41:41 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 1. Mar 27 23:41:41 volumio systemd[1]: Stopped Volumio5 Onboarding Server. Mar 27 23:41:41 volumio systemd[1]: Started Volumio5 Onboarding Server. Mar 27 23:41:41 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:41.762+01:00 level=INFO msg="running volumio5-device-gateway" version=687ad144+CHANGES buildDate=2026-02-10T16:50:24Z Mar 27 23:41:41 volumio volumio[931]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 23:41:41 volumio volumio[931]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 23:41:41 volumio volumio[931]: info: Received Get System Info Mar 27 23:41:41 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 27 23:41:41 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 27 23:41:41 volumio volumio[931]: info: Discovery: Getting this device information Mar 27 23:41:41 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Mar 27 23:41:41 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 27 23:41:41 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:41.845+01:00 level=INFO msg="system info for bfabe532d646289d8376bf5d4fab6666" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=3.912 Mar 27 23:41:41 volumio volumio[931]: info: Received Get System Info Mar 27 23:41:41 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 27 23:41:41 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 27 23:41:41 volumio volumio[931]: info: Discovery: Getting this device information Mar 27 23:41:41 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Mar 27 23:41:41 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 27 23:41:41 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 27 23:41:41 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 27 23:41:41 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:41.859+01:00 level=INFO msg="enabling local network discovery" Mar 27 23:41:41 volumio volumio[931]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Mar 27 23:41:41 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:41.947+01:00 level=INFO msg="enabling BLE discovery" Mar 27 23:41:42 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:42.080+01:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 27 23:41:42 volumio volumio[931]: info: Received Get System Info Mar 27 23:41:42 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 27 23:41:42 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 27 23:41:42 volumio volumio[931]: info: Discovery: Getting this device information Mar 27 23:41:42 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Mar 27 23:41:42 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 27 23:41:42 volumio volumio-remote-updater[561]: No test mode Mar 27 23:41:42 volumio volumio-remote-updater[561]: No alpha test mode Mar 27 23:41:42 volumio volumio[931]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 27 23:41:42 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 27 23:41:42 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 27 23:41:42 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 27 23:41:42 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 27 23:41:42 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:42.732+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Mar 27 23:41:42 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:42.733+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Mar 27 23:41:42 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:42.733+01:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Mar 27 23:41:42 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 27 23:41:42 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 27 23:41:42 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 27 23:41:43 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 27 23:41:43 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 27 23:41:44 volumio kernel: hwmon hwmon1: Voltage normalised Mar 27 23:41:44 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:44.732+01:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=eXCSINwbMXhAlY7S9mkvOL9DjNS2 tokenExpiry=2026-03-28T00:41:44.732+01:00 Mar 27 23:41:45 volumio volumio[931]: info: MYVOLUMIO: Adding device Mar 27 23:41:45 volumio volumio[931]: info: MYVOLUMIO: Evaluating Server Mar 27 23:41:45 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 27 23:41:45 volumio volumio[931]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Mar 27 23:41:46 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Mar 27 23:41:46 volumio volumio[931]: info: Setting Geolocation for MyVolumio to eu7 Mar 27 23:41:46 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 23:41:46 volumio volumio[931]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Mar 27 23:41:46 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:46.604+01:00 level=INFO msg="service successfully established" component=discovery/localnet Mar 27 23:41:47 volumio volumio[931]: info: Updating MyVolumio device info Mar 27 23:41:47 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 23:41:47 volumio volumio[931]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Mar 27 23:41:50 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:50 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Mar 27 23:41:50 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Mar 27 23:41:50 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Mar 27 23:41:50 volumio volumio[931]: info: CoreCommandRouter::volumioGetBrowseSources Mar 27 23:41:50 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 27 23:41:52 volumio volumio[931]: error: MyVolumio Plugin failed to authenticate in a timely fashion Mar 27 23:41:52 volumio volumio[931]: info: Completed starting MyVolumio Plugin Mar 27 23:41:52 volumio volumio[931]: [Metrics] CommandRouter: 86s 624.76ms Mar 27 23:41:52 volumio volumio[931]: info: CoreCommandRouter::volumiosetStartupVolume Mar 27 23:41:52 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 23:41:52 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 23:41:52 volumio volumio[931]: info: CoreCommandRouter::Close All Modals sent Mar 27 23:41:52 volumio volumio[931]: info: CoreCommandRouter::Close All Modals sent Mar 27 23:41:52 volumio volumio[931]: info: FusionDsp - ---- read samplerate, raw: Mar 27 23:41:52 volumio volumio[931]: error: FusionDsp - invalid sample rate Mar 27 23:41:52 volumio volumio[931]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Mar 27 23:41:52 volumio volumio[931]: info: FusionDsp - ---- read samplerate from file: 44100 Mar 27 23:41:52 volumio volumio[931]: info: camilladsp stopping service pid 1658... Mar 27 23:41:52 volumio volumio[931]: info: camilladsp service terminated, instance 1 Mar 27 23:41:52 volumio volumio[931]: info: FusionDsp - If filter freq >samplerate/2 then disable it Mar 27 23:41:52 volumio volumio[931]: info: FusionDsp - Effects disabled Mar 27 23:41:52 volumio volumio[931]: info: camilladsp service started and running in background, instance 1 Mar 27 23:41:53 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Mar 27 23:41:53 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 27 23:41:53 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Mar 27 23:41:58 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:58.303+01:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.26:52719 Mar 27 23:41:58 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 27 23:41:58 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 27 23:41:58 volumio volumio[931]: info: Discovery: Getting this device information Mar 27 23:41:58 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Mar 27 23:41:58 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 27 23:41:58 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:58.485+01:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.26:52719 @ 0x30d9740" latency=34.39337ms timeout=10s Mar 27 23:41:58 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:58.486+01:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.1.26:52719 @ 0x30d9740" latency=35.209869ms platform=PLATFORM_IOS version=5.260209.0 Mar 27 23:41:58 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:58.486+01:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" Mar 27 23:41:58 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 27 23:41:58 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 27 23:41:58 volumio volumio[931]: info: Received Get System Info Mar 27 23:41:58 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 27 23:41:58 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 27 23:41:58 volumio volumio[931]: info: Discovery: Getting this device information Mar 27 23:41:58 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Mar 27 23:41:58 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 27 23:41:58 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:58.503+01:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" name=Volumio Mar 27 23:41:58 volumio volumio[931]: verbose: New Socket.io Connection to 192.168.1.161:3000 from 192.168.1.26 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Mar 27 23:41:58 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:58.523+01:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" language=fr Mar 27 23:41:58 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 27 23:41:58 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 27 23:41:58 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Mar 27 23:41:58 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:58.530+01:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" timezone=Europe/Paris Mar 27 23:41:58 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:58.532+01:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" available=true connected=true macAddress=b8:27:eb:df:51:30 ip4Address=192.168.1.161/24 ip6Address= Mar 27 23:41:58 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:58.534+01:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Mar 27 23:41:58 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:58.535+01:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" setupComplete=true Mar 27 23:41:58 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Mar 27 23:41:58 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Mar 27 23:41:58 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 23:41:58 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 27 23:41:58 volumio volumio[931]: amixer -c 0 info | grep "bcm2835 ALSA" Mar 27 23:41:58 volumio volumio[931]: amixer -c 1 info | grep "bcm2835 Headphones" Mar 27 23:41:58 volumio volumio[931]: Card hw:1 'Headphones'/'bcm2835 Headphones' Mar 27 23:41:58 volumio volumio[931]: amixer -c 5 info | grep "HIFI-Ref" Mar 27 23:41:58 volumio volumio[931]: Card hw:5 'HIFIRef'/'XMOS HIFI-Ref at usb-3f980000.usb-1.4, high speed' Mar 27 23:41:59 volumio volumio[931]: amixer -c 5 info | grep "HIFI-Ref" Mar 27 23:41:59 volumio volumio[931]: Card hw:5 'HIFIRef'/'XMOS HIFI-Ref at usb-3f980000.usb-1.4, high speed' Mar 27 23:41:59 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:59.109+01:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" selectedOutputId=5 Mar 27 23:41:59 volumio volumio[931]: info: Received Get System Info Mar 27 23:41:59 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 27 23:41:59 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 27 23:41:59 volumio volumio[931]: info: Discovery: Getting this device information Mar 27 23:41:59 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Mar 27 23:41:59 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 27 23:41:59 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:59.149+01:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" currentVersion=3.912 latestVersion=3.912 Mar 27 23:41:59 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:59.150+01:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.1.26:52719 @ 0x30d9740" status=UPDATE_STATUS_NONE progress=0 Mar 27 23:41:59 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:59.150+01:00 level=INFO msg="emitting user changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" userId=eXCSINwbMXhAlY7S9mkvOL9DjNS2 Mar 27 23:41:59 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:59.151+01:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" providers=9 Mar 27 23:41:59 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:59.152+01:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" plugins=54 Mar 27 23:41:59 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Mar 27 23:41:59 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:59.159+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" state=STATUS_PLAYING positionMs=29486 volume=63 Mar 27 23:41:59 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:59.160+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" id=http://185.33.21.112:80/sax4ever_128 title="Brian Culbertson - On My Mind" Mar 27 23:41:59 volumio volumio[931]: info: BOOT COMPLETED Mar 27 23:41:59 volumio volumio[931]: info: mpdhttpout ---Boot completed detected! Patching mpd now! Mar 27 23:41:59 volumio volumio[931]: info: mpdhttpout ---Configuration successfully replaced in mpd.conf. Mar 27 23:41:59 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Mar 27 23:41:59 volumio volumio[931]: info: CoreCommandRouter::volumioPause Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::pause Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::stPlaybackTimer Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::servicePause Mar 27 23:41:59 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:59 volumio volumio[931]: info: CoreCommandRouter::servicePause Mar 27 23:41:59 volumio volumio[931]: info: [1774651319693] ControllerWebradio::pause Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand pause Mar 27 23:41:59 volumio volumio[931]: info: mpdhttpout --- Volumio set on pause Mar 27 23:41:59 volumio volumio[931]: info: sendMpdCommand pause took 6 milliseconds Mar 27 23:41:59 volumio volumio[931]: info: Mar 27 23:41:59 volumio volumio[931]: ---------------------------- MPD announces state update: player Mar 27 23:41:59 volumio volumio[931]: info: ControllerMpd::getState Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand status Mar 27 23:41:59 volumio volumio[931]: info: Mar 27 23:41:59 volumio volumio[931]: ---------------------------- MPD announces state update: player Mar 27 23:41:59 volumio volumio[931]: info: ControllerMpd::getState Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand status Mar 27 23:41:59 volumio volumio[931]: info: Mar 27 23:41:59 volumio volumio[931]: ---------------------------- MPD announces state update: player Mar 27 23:41:59 volumio volumio[931]: info: ControllerMpd::getState Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand status Mar 27 23:41:59 volumio volumio[931]: info: Mar 27 23:41:59 volumio volumio[931]: ---------------------------- MPD announces state update: player Mar 27 23:41:59 volumio volumio[931]: info: ControllerMpd::getState Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand status Mar 27 23:41:59 volumio volumio[931]: info: Mar 27 23:41:59 volumio volumio[931]: ---------------------------- MPD announces state update: player Mar 27 23:41:59 volumio volumio[931]: info: ControllerMpd::getState Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand status Mar 27 23:41:59 volumio volumio[931]: info: Mar 27 23:41:59 volumio volumio[931]: ---------------------------- MPD announces state update: player Mar 27 23:41:59 volumio volumio[931]: info: ControllerMpd::getState Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand status Mar 27 23:41:59 volumio volumio[931]: info: Mar 27 23:41:59 volumio volumio[931]: ---------------------------- MPD announces state update: player Mar 27 23:41:59 volumio volumio[931]: info: ControllerMpd::getState Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand status Mar 27 23:41:59 volumio volumio[931]: info: sendMpdCommand status took 27 milliseconds Mar 27 23:41:59 volumio volumio[931]: info: sendMpdCommand status took 23 milliseconds Mar 27 23:41:59 volumio volumio[931]: info: sendMpdCommand status took 21 milliseconds Mar 27 23:41:59 volumio volumio[931]: info: sendMpdCommand status took 19 milliseconds Mar 27 23:41:59 volumio volumio[931]: info: sendMpdCommand status took 16 milliseconds Mar 27 23:41:59 volumio volumio[931]: info: sendMpdCommand status took 15 milliseconds Mar 27 23:41:59 volumio volumio[931]: info: sendMpdCommand status took 9 milliseconds Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::parseState Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::parseState Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::parseState Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::parseState Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::parseState Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::parseState Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::parseState Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 27 23:41:59 volumio volumio[931]: info: sendMpdCommand playlistinfo took 18 milliseconds Mar 27 23:41:59 volumio volumio[931]: info: sendMpdCommand playlistinfo took 13 milliseconds Mar 27 23:41:59 volumio volumio[931]: info: sendMpdCommand playlistinfo took 12 milliseconds Mar 27 23:41:59 volumio volumio[931]: info: sendMpdCommand playlistinfo took 12 milliseconds Mar 27 23:41:59 volumio volumio[931]: info: sendMpdCommand playlistinfo took 11 milliseconds Mar 27 23:41:59 volumio volumio[931]: info: sendMpdCommand playlistinfo took 11 milliseconds Mar 27 23:41:59 volumio volumio[931]: info: sendMpdCommand playlistinfo took 10 milliseconds Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::parseTrackInfo Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::parseTrackInfo Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::parseTrackInfo Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::parseTrackInfo Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::parseTrackInfo Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::parseTrackInfo Mar 27 23:41:59 volumio volumio[931]: verbose: ControllerMpd::parseTrackInfo Mar 27 23:41:59 volumio volumio[931]: info: ControllerMpd::pushState Mar 27 23:41:59 volumio volumio[931]: info: CoreCommandRouter::servicePushState Mar 27 23:41:59 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:59 volumio volumio[931]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":26004,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Brian Culbertson - On My Mind","artist":"1.FM - Sax4Ever","album":null,"uri":"http://185.33.21.112:80/sax4ever_128","trackType":""} Mar 27 23:41:59 volumio volumio[931]: verbose: CURRENT POSITION 0 Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::syncState stateService pause Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::syncState currentStatus pause Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:59 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 27 23:41:59 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::stPlaybackTimer Mar 27 23:41:59 volumio volumio[931]: info: ControllerMpd::pushState Mar 27 23:41:59 volumio volumio[931]: info: CoreCommandRouter::servicePushState Mar 27 23:41:59 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:59 volumio volumio[931]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":26004,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Brian Culbertson - On My Mind","artist":"1.FM - Sax4Ever","album":null,"uri":"http://185.33.21.112:80/sax4ever_128","trackType":""} Mar 27 23:41:59 volumio volumio[931]: verbose: CURRENT POSITION 0 Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::syncState stateService pause Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::syncState currentStatus pause Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:59 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::stPlaybackTimer Mar 27 23:41:59 volumio volumio[931]: info: ControllerMpd::pushState Mar 27 23:41:59 volumio volumio[931]: info: CoreCommandRouter::servicePushState Mar 27 23:41:59 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:59 volumio volumio[931]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":26004,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Brian Culbertson - On My Mind","artist":"1.FM - Sax4Ever","album":null,"uri":"http://185.33.21.112:80/sax4ever_128","trackType":""} Mar 27 23:41:59 volumio volumio[931]: verbose: CURRENT POSITION 0 Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::syncState stateService pause Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::syncState currentStatus pause Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:59 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::stPlaybackTimer Mar 27 23:41:59 volumio volumio[931]: info: ControllerMpd::pushState Mar 27 23:41:59 volumio volumio[931]: info: CoreCommandRouter::servicePushState Mar 27 23:41:59 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:59 volumio volumio[931]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":26004,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Brian Culbertson - On My Mind","artist":"1.FM - Sax4Ever","album":null,"uri":"http://185.33.21.112:80/sax4ever_128","trackType":""} Mar 27 23:41:59 volumio volumio[931]: verbose: CURRENT POSITION 0 Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::syncState stateService pause Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::syncState currentStatus pause Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:59 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::stPlaybackTimer Mar 27 23:41:59 volumio volumio[931]: info: ControllerMpd::pushState Mar 27 23:41:59 volumio volumio[931]: info: CoreCommandRouter::servicePushState Mar 27 23:41:59 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:59 volumio volumio[931]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":26004,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Brian Culbertson - On My Mind","artist":"1.FM - Sax4Ever","album":null,"uri":"http://185.33.21.112:80/sax4ever_128","trackType":""} Mar 27 23:41:59 volumio volumio[931]: verbose: CURRENT POSITION 0 Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::syncState stateService pause Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::syncState currentStatus pause Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:59 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::stPlaybackTimer Mar 27 23:41:59 volumio volumio[931]: info: ControllerMpd::pushState Mar 27 23:41:59 volumio volumio[931]: info: CoreCommandRouter::servicePushState Mar 27 23:41:59 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:59 volumio volumio[931]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":26004,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Brian Culbertson - On My Mind","artist":"1.FM - Sax4Ever","album":null,"uri":"http://185.33.21.112:80/sax4ever_128","trackType":""} Mar 27 23:41:59 volumio volumio[931]: verbose: CURRENT POSITION 0 Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::syncState stateService pause Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::syncState currentStatus pause Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:59 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::stPlaybackTimer Mar 27 23:41:59 volumio volumio[931]: info: ControllerMpd::pushState Mar 27 23:41:59 volumio volumio[931]: info: CoreCommandRouter::servicePushState Mar 27 23:41:59 volumio volumio[931]: info: CorePlayQueue::getTrack 0 Mar 27 23:41:59 volumio volumio[931]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":26004,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Brian Culbertson - On My Mind","artist":"1.FM - Sax4Ever","album":null,"uri":"http://185.33.21.112:80/sax4ever_128","trackType":""} Mar 27 23:41:59 volumio volumio[931]: verbose: CURRENT POSITION 0 Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::syncState stateService pause Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::syncState currentStatus pause Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::pushState Mar 27 23:41:59 volumio volumio[931]: info: CoreCommandRouter::volumioPushState Mar 27 23:41:59 volumio volumio[931]: info: CoreStateMachine::stPlaybackTimer Mar 27 23:41:59 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:59.874+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" state=STATUS_PAUSED positionMs=29986 volume=63 Mar 27 23:41:59 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:59.875+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" id=http://185.33.21.112:80/sax4ever_128 title="Brian Culbertson - On My Mind" Mar 27 23:41:59 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:59.880+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" state=STATUS_PAUSED positionMs=29986 volume=63 Mar 27 23:41:59 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:59.881+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" id=http://185.33.21.112:80/sax4ever_128 title="Brian Culbertson - On My Mind" Mar 27 23:41:59 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:59.883+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" state=STATUS_PAUSED positionMs=29986 volume=63 Mar 27 23:41:59 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:59.884+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" id=http://185.33.21.112:80/sax4ever_128 title="Brian Culbertson - On My Mind" Mar 27 23:41:59 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:59.886+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" state=STATUS_PAUSED positionMs=29986 volume=63 Mar 27 23:41:59 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:59.886+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" id=http://185.33.21.112:80/sax4ever_128 title="Brian Culbertson - On My Mind" Mar 27 23:41:59 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:59.889+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" state=STATUS_PAUSED positionMs=29986 volume=63 Mar 27 23:41:59 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:59.889+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" id=http://185.33.21.112:80/sax4ever_128 title="Brian Culbertson - On My Mind" Mar 27 23:41:59 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:59.891+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" state=STATUS_PAUSED positionMs=29986 volume=63 Mar 27 23:41:59 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:59.892+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" id=http://185.33.21.112:80/sax4ever_128 title="Brian Culbertson - On My Mind" Mar 27 23:41:59 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:59.897+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" state=STATUS_PAUSED positionMs=29986 volume=63 Mar 27 23:41:59 volumio volumio5-onboarding[1809]: time=2026-03-27T23:41:59.897+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" id=http://185.33.21.112:80/sax4ever_128 title="Brian Culbertson - On My Mind" Mar 27 23:41:59 volumio volumio[931]: info: ------------------------------ 207ms Mar 27 23:41:59 volumio volumio[931]: info: ------------------------------ 203ms Mar 27 23:41:59 volumio volumio[931]: info: ------------------------------ 200ms Mar 27 23:41:59 volumio volumio[931]: info: ------------------------------ 199ms Mar 27 23:41:59 volumio volumio[931]: info: ------------------------------ 197ms Mar 27 23:41:59 volumio volumio[931]: info: ------------------------------ 196ms Mar 27 23:41:59 volumio volumio[931]: info: ------------------------------ 191ms Mar 27 23:41:59 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status pause Mar 27 23:41:59 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status pause Mar 27 23:42:00 volumio sudo[1934]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Mar 27 23:42:00 volumio sudo[1934]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:42:00 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status pause Mar 27 23:42:00 volumio sudo[1938]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Mar 27 23:42:00 volumio sudo[1938]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:42:00 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status pause Mar 27 23:42:00 volumio sudo[1934]: pam_unix(sudo:session): session closed for user root Mar 27 23:42:00 volumio sudo[1941]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Mar 27 23:42:00 volumio sudo[1941]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:42:00 volumio sudo[1938]: pam_unix(sudo:session): session closed for user root Mar 27 23:42:00 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status pause Mar 27 23:42:00 volumio sudo[1941]: pam_unix(sudo:session): session closed for user root Mar 27 23:42:00 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status pause Mar 27 23:42:00 volumio sudo[1943]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Mar 27 23:42:00 volumio sudo[1943]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:42:00 volumio volumio[931]: info: PeppyMeterBasic ---peppymeterbasic status pause Mar 27 23:42:00 volumio sudo[1943]: pam_unix(sudo:session): session closed for user root Mar 27 23:42:00 volumio sudo[1946]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Mar 27 23:42:00 volumio sudo[1946]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:42:00 volumio sudo[1949]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Mar 27 23:42:00 volumio sudo[1949]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:42:00 volumio volumio[931]: info: peppymeterbasic Daemon Stop Mar 27 23:42:00 volumio volumio[931]: info: peppymeterbasic Daemon Stop Mar 27 23:42:00 volumio volumio[931]: info: peppymeterbasic Daemon Stop Mar 27 23:42:00 volumio volumio[931]: info: peppymeterbasic Daemon Stop Mar 27 23:42:00 volumio sudo[1951]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Mar 27 23:42:00 volumio sudo[1951]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:42:00 volumio sudo[1946]: pam_unix(sudo:session): session closed for user root Mar 27 23:42:00 volumio sudo[1949]: pam_unix(sudo:session): session closed for user root Mar 27 23:42:00 volumio sudo[1951]: pam_unix(sudo:session): session closed for user root Mar 27 23:42:00 volumio volumio[931]: info: peppymeterbasic Daemon Stop Mar 27 23:42:00 volumio volumio[931]: info: peppymeterbasic Daemon Stop Mar 27 23:42:00 volumio volumio[931]: info: peppymeterbasic Daemon Stop Mar 27 23:42:00 volumio volumio5-onboarding[1809]: time=2026-03-27T23:42:00.404+01:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.26:52719 @ 0x30d9740" latency=80.423503ms timeout=10s Mar 27 23:42:00 volumio volumio5-onboarding[1809]: time=2026-03-27T23:42:00.404+01:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" Mar 27 23:42:00 volumio volumio5-onboarding[1809]: time=2026-03-27T23:42:00.404+01:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.1.26:52719 @ 0x30d9740" latency=81.355947ms platform=PLATFORM_IOS version=5.260209.0 Mar 27 23:42:00 volumio volumio[931]: info: Received Get System Info Mar 27 23:42:00 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 27 23:42:00 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 27 23:42:00 volumio volumio[931]: info: Discovery: Getting this device information Mar 27 23:42:00 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Mar 27 23:42:00 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 27 23:42:00 volumio volumio5-onboarding[1809]: time=2026-03-27T23:42:00.412+01:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" name=Volumio Mar 27 23:42:00 volumio volumio5-onboarding[1809]: time=2026-03-27T23:42:00.413+01:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" language=fr Mar 27 23:42:00 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Mar 27 23:42:00 volumio volumio5-onboarding[1809]: time=2026-03-27T23:42:00.418+01:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" timezone=Europe/Paris Mar 27 23:42:00 volumio volumio5-onboarding[1809]: time=2026-03-27T23:42:00.419+01:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" available=true connected=true macAddress=b8:27:eb:df:51:30 ip4Address=192.168.1.161/24 ip6Address= Mar 27 23:42:00 volumio volumio5-onboarding[1809]: time=2026-03-27T23:42:00.420+01:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Mar 27 23:42:00 volumio volumio5-onboarding[1809]: time=2026-03-27T23:42:00.421+01:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" setupComplete=true Mar 27 23:42:00 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Mar 27 23:42:00 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Mar 27 23:42:00 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 23:42:00 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 27 23:42:00 volumio volumio[931]: amixer -c 0 info | grep "bcm2835 ALSA" Mar 27 23:42:00 volumio volumio[931]: amixer -c 1 info | grep "bcm2835 Headphones" Mar 27 23:42:00 volumio volumio[931]: Card hw:1 'Headphones'/'bcm2835 Headphones' Mar 27 23:42:00 volumio kernel: hwmon hwmon1: Undervoltage detected! Mar 27 23:42:00 volumio volumio[931]: amixer -c 5 info | grep "HIFI-Ref" Mar 27 23:42:01 volumio volumio[931]: Card hw:5 'HIFIRef'/'XMOS HIFI-Ref at usb-3f980000.usb-1.4, high speed' Mar 27 23:42:01 volumio volumio[931]: amixer -c 5 info | grep "HIFI-Ref" Mar 27 23:42:01 volumio volumio5-onboarding[1809]: time=2026-03-27T23:42:01.223+01:00 level=INFO msg="new address was allocated" component=ble/conn old=1 new=2 Mar 27 23:42:01 volumio volumio[931]: Card hw:5 'HIFIRef'/'XMOS HIFI-Ref at usb-3f980000.usb-1.4, high speed' Mar 27 23:42:01 volumio volumio5-onboarding[1809]: time=2026-03-27T23:42:01.331+01:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" selectedOutputId=5 Mar 27 23:42:01 volumio volumio[931]: info: Received Get System Info Mar 27 23:42:01 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 27 23:42:01 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 27 23:42:01 volumio volumio[931]: info: Discovery: Getting this device information Mar 27 23:42:01 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Mar 27 23:42:01 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 27 23:42:01 volumio volumio5-onboarding[1809]: time=2026-03-27T23:42:01.369+01:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" currentVersion=3.912 latestVersion=3.912 Mar 27 23:42:01 volumio volumio5-onboarding[1809]: time=2026-03-27T23:42:01.370+01:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.1.26:52719 @ 0x30d9740" status=UPDATE_STATUS_NONE progress=0 Mar 27 23:42:01 volumio volumio5-onboarding[1809]: time=2026-03-27T23:42:01.370+01:00 level=INFO msg="emitting user changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" userId=eXCSINwbMXhAlY7S9mkvOL9DjNS2 Mar 27 23:42:01 volumio volumio5-onboarding[1809]: time=2026-03-27T23:42:01.371+01:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" providers=9 Mar 27 23:42:01 volumio volumio5-onboarding[1809]: time=2026-03-27T23:42:01.372+01:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" plugins=54 Mar 27 23:42:01 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Mar 27 23:42:01 volumio volumio5-onboarding[1809]: time=2026-03-27T23:42:01.389+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" state=STATUS_PAUSED positionMs=30301 volume=63 Mar 27 23:42:01 volumio volumio5-onboarding[1809]: time=2026-03-27T23:42:01.390+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.26:52719 @ 0x30d9740" id=http://185.33.21.112:80/sax4ever_128 title="Brian Culbertson - On My Mind" Mar 27 23:42:01 volumio dbus-daemon[551]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.21" (uid=0 pid=1809 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.4" (uid=0 pid=699 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Mar 27 23:42:01 volumio volumio5-onboarding[1809]: time=2026-03-27T23:42:01.489+01:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.26:52719 @ 0x30d9740" latency=19.255739ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Mar 27 23:42:01 volumio dbus-daemon[551]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.21" (uid=0 pid=1809 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.4" (uid=0 pid=699 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Mar 27 23:42:01 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Mar 27 23:42:01 volumio sudo[1996]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 27 23:42:01 volumio sudo[1996]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:42:01 volumio systemd[1]: Stopping Music Player Daemon... Mar 27 23:42:02 volumio volumio[931]: error: Upnp client error: Error: This socket has been ended by the other party Mar 27 23:42:02 volumio systemd[1]: mpd.service: Succeeded. Mar 27 23:42:02 volumio systemd[1]: Stopped Music Player Daemon. Mar 27 23:42:02 volumio systemd[1]: Starting Music Player Daemon... Mar 27 23:42:02 volumio sudo[1998]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 27 23:42:02 volumio sudo[1998]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:42:02 volumio sudo[1998]: pam_unix(sudo:session): session closed for user root Mar 27 23:42:03 volumio sudo[2002]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 27 23:42:03 volumio sudo[2002]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:42:03 volumio sudo[2002]: pam_unix(sudo:session): session closed for user root Mar 27 23:42:04 volumio sudo[2004]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 27 23:42:04 volumio sudo[2004]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:42:04 volumio sudo[2004]: pam_unix(sudo:session): session closed for user root Mar 27 23:42:04 volumio volumio5-onboarding[1809]: time=2026-03-27T23:42:04.161+01:00 level=INFO msg="new address was allocated" component=ble/conn old=2 new=3 Mar 27 23:42:04 volumio volumio[931]: verbose: New Socket.io Connection to 192.168.1.161 from 192.168.1.26 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 9 Mar 27 23:42:04 volumio dbus-daemon[551]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.21" (uid=0 pid=1809 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.4" (uid=0 pid=699 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Mar 27 23:42:04 volumio dbus-daemon[551]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.21" (uid=0 pid=1809 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.4" (uid=0 pid=699 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Mar 27 23:42:05 volumio mpd[2000]: Mar 27 23:42 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 27 23:42:05 volumio volumio5-onboarding[1809]: time=2026-03-27T23:42:05.993+01:00 level=INFO msg="new address was allocated" component=ble/conn old=3 new=4 Mar 27 23:42:06 volumio systemd[1]: Started Music Player Daemon. Mar 27 23:42:06 volumio sudo[1996]: pam_unix(sudo:session): session closed for user root Mar 27 23:42:06 volumio volumio[931]: error: updateQueue error: null Mar 27 23:42:06 volumio dbus-daemon[551]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.21" (uid=0 pid=1809 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.4" (uid=0 pid=699 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Mar 27 23:42:06 volumio sudo[2018]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 27 23:42:06 volumio sudo[2018]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:42:06 volumio sudo[2018]: pam_unix(sudo:session): session closed for user root Mar 27 23:42:06 volumio sudo[2020]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 27 23:42:06 volumio sudo[2020]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:42:06 volumio sudo[2020]: pam_unix(sudo:session): session closed for user root Mar 27 23:42:06 volumio dbus-daemon[551]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.21" (uid=0 pid=1809 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.4" (uid=0 pid=699 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Mar 27 23:42:06 volumio volumio[931]: verbose: New Socket.io Connection to 192.168.1.161 from 192.168.1.26 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 10 Mar 27 23:42:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 27 23:42:06 volumio volumio[931]: info: CoreCommandRouter::volumioGetVisibleSources Mar 27 23:42:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 27 23:42:06 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Mar 27 23:42:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 27 23:42:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 27 23:42:06 volumio volumio[931]: info: Received Get System Info Mar 27 23:42:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 27 23:42:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 27 23:42:06 volumio volumio[931]: info: Discovery: Getting this device information Mar 27 23:42:06 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Mar 27 23:42:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 27 23:42:06 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Mar 27 23:42:06 volumio volumio[931]: info: Listing playlists Mar 27 23:42:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Mar 27 23:42:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 27 23:42:06 volumio volumio[931]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 27 23:42:06 volumio volumio[931]: info: FusionDsp - no preset used Mar 27 23:42:06 volumio volumio[931]: info: FusionDsp - .Bass-FusionDsp.json,.Classic-FusionDsp.json,.Rock-FusionDsp.json,.Soundtrack-FusionDsp.json,.Voice-FusionDsp.json Mar 27 23:42:06 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 27 23:42:07 volumio kernel: hwmon hwmon1: Voltage normalised Mar 27 23:42:08 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Mar 27 23:42:08 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 27 23:42:08 volumio volumio[931]: info: Received Get System Info Mar 27 23:42:08 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 27 23:42:08 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 27 23:42:08 volumio volumio[931]: info: Discovery: Getting this device information Mar 27 23:42:08 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Mar 27 23:42:08 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 27 23:42:08 volumio volumio[1263]: ..................................................................................................................................................................................................................................................++++ Mar 27 23:42:09 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 27 23:42:09 volumio volumio[931]: info: Received Get System Info Mar 27 23:42:09 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 27 23:42:09 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 27 23:42:09 volumio volumio[931]: info: Discovery: Getting this device information Mar 27 23:42:09 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Mar 27 23:42:09 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 27 23:42:12 volumio volumio[1263]: ...........................++++ Mar 27 23:42:12 volumio volumio[1263]: e is 65537 (0x010001) Mar 27 23:42:12 volumio volumio[1263]: writing RSA key Mar 27 23:42:16 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Mar 27 23:42:24 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 27 23:42:24 volumio volumio[931]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Mar 27 23:42:24 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Mar 27 23:42:24 volumio volumio[931]: info: Received Get System Version Mar 27 23:42:24 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 27 23:42:24 volumio volumio[931]: info: Received Get System Info Mar 27 23:42:24 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 27 23:42:24 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 27 23:42:24 volumio volumio[931]: info: Discovery: Getting this device information Mar 27 23:42:24 volumio volumio[931]: info: CoreCommandRouter::volumioGetState Mar 27 23:42:24 volumio volumio[931]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 27 23:42:29 volumio volumio[931]: info: ___________ PLUGINS: Run onVolumioReboot Tasks ___________ Mar 27 23:42:29 volumio volumio[931]: info: PLUGIN onReboot : networkfs Mar 27 23:42:30 volumio sudo[2121]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/umount -f /mnt/NAS/Volume_1 Mar 27 23:42:30 volumio sudo[2121]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:42:30 volumio sudo[2121]: pam_unix(sudo:session): session closed for user root Mar 27 23:42:30 volumio volumio[931]: umount: /mnt/NAS/Volume_1: target is busy. Mar 27 23:42:30 volumio volumio[931]: error: Cannot umount share Volume_1 : Error: Command failed: /usr/bin/sudo /bin/umount -f /mnt/NAS/Volume_1 Mar 27 23:42:30 volumio volumio[931]: umount: /mnt/NAS/Volume_1: target is busy. Mar 27 23:42:30 volumio sudo[2124]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/umount -f /mnt/NAS/Volume_2 Mar 27 23:42:30 volumio sudo[2124]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 23:42:30 volumio systemd[1]: mnt-NAS-Volume_2.mount: Succeeded. Mar 27 23:42:30 volumio sudo[2124]: pam_unix(sudo:session): session closed for user root Mar 27 23:42:30 volumio volumio[931]: info: PLUGIN onReboot : audiophonicsonoff Mar 27 23:42:30 volumio volumio[931]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 27 23:42:30 volumio volumio[931]: TypeError: Cannot read property 'writeSync' of undefined Mar 27 23:42:30 volumio volumio[931]: at ControllerAudiophonicsOnOff.onVolumioReboot (/data/plugins/system_controller/audiophonicsonoff/index.js:35:25) Mar 27 23:42:30 volumio volumio[931]: at PluginManager.onVolumioRebootPlugin (/volumio/app/pluginmanager.js:684:30) Mar 27 23:42:30 volumio volumio[931]: at HashMap. (/volumio/app/pluginmanager.js:668:31) Mar 27 23:42:30 volumio volumio[931]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Mar 27 23:42:30 volumio volumio[931]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Mar 27 23:42:30 volumio volumio[931]: at PluginManager.onVolumioReboot (/volumio/app/pluginmanager.js:666:20) Mar 27 23:42:30 volumio volumio[931]: at CoreCommandRouter.reboot (/volumio/app/index.js:1350:22) Mar 27 23:42:30 volumio volumio[931]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:870:33) Mar 27 23:42:30 volumio volumio[931]: at Socket.emit (events.js:315:20) Mar 27 23:42:30 volumio volumio[931]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Mar 27 23:42:30 volumio volumio[931]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Mar 27 23:42:30 volumio volumio[931]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 27 23:42:31 volumio sudo[2150]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-03-27 23:41 Mar 27 23:42:31 volumio sudo[2150]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="464fc672d77d3df6ee72b331d36cdf1fa936e1ec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 10:59:40 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="37c6ab864cb114e1344d540995c69f86"