-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Sat 2025-06-28 20:14:10 CEST. -- Jun 28 20:13:00 volumio.local volumio[1149]: info: Loading plugin "i2s_dacs"... Jun 28 20:13:00 volumio.local volumio[1149]: info: Loading plugin "volumiodiscovery"... Jun 28 20:13:00 volumio.local volumio[1149]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 28 20:13:00 volumio.local volumio[1149]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 28 20:13:00 volumio.local node[1149]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 28 20:13:00 volumio.local volumio[1149]: *** WARNING *** For more information see Jun 28 20:13:00 volumio.local volumio[1149]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 28 20:13:00 volumio.local volumio[1149]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 28 20:13:00 volumio.local volumio[1149]: *** WARNING *** For more information see Jun 28 20:13:00 volumio.local node[1149]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 28 20:13:00 volumio.local node[1149]: *** WARNING *** For more information see Jun 28 20:13:00 volumio.local node[1149]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 28 20:13:00 volumio.local node[1149]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 28 20:13:00 volumio.local node[1149]: *** WARNING *** For more information see Jun 28 20:13:00 volumio.local volumio[1149]: info: Applying required configuration parameters for plugin volumiodiscovery Jun 28 20:13:00 volumio.local volumio[1149]: info: Discovery: Started advertising with name: volumio.local Jun 28 20:13:00 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 28 20:13:00 volumio.local volumio[1149]: info: Loading plugin "spop"... Jun 28 20:13:01 volumio.local volumio[1149]: info: Loading plugin "outputs"... Jun 28 20:13:01 volumio.local volumio[1149]: info: Loading plugin "albumart"... Jun 28 20:13:01 volumio.local volumio[1149]: info: Plugin example_plugin is not enabled Jun 28 20:13:01 volumio.local volumio[1149]: info: Loading plugin "inputs"... Jun 28 20:13:01 volumio.local volumio[1149]: info: Loading plugin "updater_comm"... Jun 28 20:13:01 volumio.local volumio[1149]: info: Plugin mpdemulation is not enabled Jun 28 20:13:01 volumio.local volumio[1149]: info: Loading plugin "rest_api"... Jun 28 20:13:01 volumio.local volumio[1149]: info: Loading plugin "websocket"... Jun 28 20:13:01 volumio.local volumio[1149]: info: Starting Socket.io Server version 2.3.0 Jun 28 20:13:01 volumio.local volumio[1149]: info: Loading plugin "fusiondsp"... Jun 28 20:13:01 volumio.local volumio[1149]: Forking 3 albumart workers Jun 28 20:13:01 volumio.local volumio[1149]: info: Applying required configuration parameters for plugin fusiondsp Jun 28 20:13:01 volumio.local volumio[1149]: info: Loading plugin "minidlna"... Jun 28 20:13:01 volumio.local volumio[1149]: info: Applying required configuration parameters for plugin minidlna Jun 28 20:13:01 volumio.local volumio[1149]: Starting albumart workers Jun 28 20:13:02 volumio.local volumio[1149]: Starting albumart workers Jun 28 20:13:02 volumio.local volumio[1149]: Starting albumart workers Jun 28 20:13:02 volumio.local volumio[1149]: info: Loading i18n strings for locale de Jun 28 20:13:02 volumio.local volumio[1149]: Updating browse sources language Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 28 20:13:02 volumio.local sudo[1192]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreCommandRouter::initPlayerControls Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 28 20:13:02 volumio.local volumio[1149]: Express server listening on port 3000 Jun 28 20:13:02 volumio.local volumio[1149]: [Metrics] WebUI: 5s 966.88ms Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreStateMachine::resetVolumioState Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreStateMachine::getcurrentVolume Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreCommandRouter::volumioRetrievevolume Jun 28 20:13:02 volumio.local volumio[1149]: info: Volumio Network Manager: Network status updated: 3 Jun 28 20:13:02 volumio.local volumio-remote-updater[644]: [2025-06-28 20:13:02] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1751134379 101 Jun 28 20:13:02 volumio.local volumio[1149]: 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: 1 Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:02 volumio.local volumio[1149]: info: Executing start script for DAC IQaudIO Pi-DigiAMP+ Jun 28 20:13:02 volumio.local volumio[1149]: info: Reloading queue from file Jun 28 20:13:02 volumio.local volumio[1149]: info: Setting Device type: Raspberry PI Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreStateMachine::setRepeat null single undefined Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreStateMachine::pushState Jun 28 20:13:02 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPushState Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreStateMachine::setRandom null Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreStateMachine::pushState Jun 28 20:13:02 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPushState Jun 28 20:13:02 volumio.local volumio[1149]: info: VolumeController:: Volume=75 Mute =false Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreStateMachine::pushState Jun 28 20:13:02 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPushState Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreStateMachine::updateTrackBlock Jun 28 20:13:02 volumio.local volumio[1149]: info: CorePlayQueue::getTrackBlock Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreCommandRouter::volumioRetrievevolume Jun 28 20:13:02 volumio.local volumio[1149]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Jun 28 20:13:02 volumio.local volumio[1149]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03114 Jun 28 20:13:02 volumio.local volumio[1149]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Jun 28 20:13:02 volumio.local volumio[1149]: info: DAC script executed Jun 28 20:13:02 volumio.local volumio[1149]: info: Completed loading Core Plugins Jun 28 20:13:02 volumio.local volumio[1149]: info: Preparing to generate the ALSA configuration file Jun 28 20:13:02 volumio.local volumio[1149]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jun 28 20:13:02 volumio.local volumio[1149]: info: Reading ALSA contributions from plugins. Jun 28 20:13:02 volumio.local volumio[1149]: info: Discovery: adding 66ebef1d-3a56-478f-aff0-cbc181e632c8 Jun 28 20:13:02 volumio.local volumio[1149]: info: Discovery: Found device volumio.local Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreCommandRouter::volumioGetState Jun 28 20:13:02 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:02 volumio.local volumio[1149]: info: Discovery: this is already registered, 66ebef1d-3a56-478f-aff0-cbc181e632c8 Jun 28 20:13:02 volumio.local volumio[1149]: info: Discovery: Found device volumio.local Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreCommandRouter::volumioGetState Jun 28 20:13:02 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:02 volumio.local volumio[1149]: info: VolumeController:: Volume=75 Mute =false Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreStateMachine::pushState Jun 28 20:13:02 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPushState Jun 28 20:13:02 volumio.local volumio[1149]: info: Asound.conf file written Jun 28 20:13:02 volumio.local sudo[1310]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Jun 28 20:13:02 volumio.local sudo[1310]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:02 volumio.local sudo[1310]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:02 volumio.local volumio[1149]: info: Output device has changed, restarting MPD Jun 28 20:13:02 volumio.local sudo[1315]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 28 20:13:02 volumio.local sudo[1315]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:02 volumio.local volumio[1149]: info: Output device has changed, restarting Shairport Sync Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:02 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:02 volumio.local sudo[1315]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:02 volumio.local sudo[1317]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 28 20:13:02 volumio.local sudo[1317]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:02 volumio.local systemd[1]: Stopping Music Player Daemon... Jun 28 20:13:03 volumio.local volumio[1149]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 28 20:13:03 volumio.local volumio[1149]: info: ___________ START PLUGINS ___________ Jun 28 20:13:03 volumio.local volumio[1149]: info: ControllerMpd::onStart: Initializing MPD Jun 28 20:13:03 volumio.local volumio[1149]: info: Creating MPD Configuration file Jun 28 20:13:03 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 28 20:13:03 volumio.local volumio[1149]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 28 20:13:03 volumio.local volumio[1149]: info: [1751134383045] CoreMusicLibrary::Adding element Medienserver Jun 28 20:13:03 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 28 20:13:03 volumio.local sudo[1324]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 28 20:13:03 volumio.local sudo[1324]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:03 volumio.local sudo[1324]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:03 volumio.local sudo[1326]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 28 20:13:03 volumio.local sudo[1326]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:03 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:03 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:03 volumio.local systemd[1]: mpd.service: Succeeded. Jun 28 20:13:03 volumio.local systemd[1]: Stopped Music Player Daemon. Jun 28 20:13:03 volumio.local volumio[1149]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 28 20:13:03 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:03 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:03 volumio.local volumio[1149]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 28 20:13:03 volumio.local volumio[1149]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 28 20:13:03 volumio.local volumio[1149]: info: [1751134383135] CoreMusicLibrary::Adding element Last_100 Jun 28 20:13:03 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 28 20:13:03 volumio.local volumio[1149]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 28 20:13:03 volumio.local volumio[1149]: info: [1751134383137] CoreMusicLibrary::Adding element Webradio Jun 28 20:13:03 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 28 20:13:03 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 28 20:13:03 volumio.local volumio[1149]: info: Initializing BBC Radios Jun 28 20:13:03 volumio.local systemd[1]: Starting Music Player Daemon... Jun 28 20:13:03 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 28 20:13:03 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:03 volumio.local volumio[1149]: info: Creating Spotify config file Jun 28 20:13:03 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:03 volumio.local sudo[1332]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 28 20:13:03 volumio.local sudo[1332]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:03 volumio.local sudo[1332]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:03 volumio.local volumio[1149]: info: Loading i18n strings for locale de Jun 28 20:13:03 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jun 28 20:13:03 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:03 volumio.local volumio[1149]: info: FusionDsp - mixtype--------------------- Hardware Jun 28 20:13:03 volumio.local volumio[1149]: info: Loading i18n strings for locale de Jun 28 20:13:03 volumio.local volumio[1149]: info: Volumio Calling Home Jun 28 20:13:03 volumio.local volumio[1149]: info: Preparing to generate the ALSA configuration file Jun 28 20:13:03 volumio.local volumio[1149]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jun 28 20:13:03 volumio.local volumio[1149]: info: Reading ALSA contributions from plugins. Jun 28 20:13:03 volumio.local volumio[1149]: info: MPD Permissions set Jun 28 20:13:03 volumio.local volumio[1149]: info: MPD Permissions set Jun 28 20:13:03 volumio.local volumio[1149]: info: Volumio called home Jun 28 20:13:03 volumio.local volumio[1149]: info: Spotify config file written Jun 28 20:13:03 volumio.local sudo[1354]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jun 28 20:13:03 volumio.local sudo[1354]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:03 volumio.local volumio[1149]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jun 28 20:13:03 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:03 volumio.local systemd[1]: Started go-librespot Daemon. Jun 28 20:13:03 volumio.local go-librespot[1356]: go-librespot daemon starting... Jun 28 20:13:03 volumio.local sudo[1354]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:03 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:03 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:03 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:03 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:03 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:03 volumio.local volumio[1149]: info: No need to fix Spotify hosts Jun 28 20:13:03 volumio.local volumio[1149]: info: minidlna: Found miniDLNA version 1.2.1 Jun 28 20:13:03 volumio.local volumio[1149]: info: minidlna: Starting minidlna.service Jun 28 20:13:03 volumio.local sudo[1372]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start minidlna.service Jun 28 20:13:03 volumio.local sudo[1372]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:03 volumio.local volumio[1149]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jun 28 20:13:03 volumio.local volumio[1149]: SPOTIFY: BQA-SEbQURbX21NV1bihrhh8Jm9AUKHXt8NrTbaFDoXSHq1ALviFpetxrRBogcl0XDyhigflxth369lDSsc8l38CDLBFMnXg2j85IPM2NSBsxfddVi056JjYNx4_L1lOob1QQhsbs4XTq3KFcNY2hM4IUTHydEWnrgpMG6zkzB53O2Wq3Zhi7Tp_b9mU7ob5oCLyJ5UxG23T4UhtEX77dDXoQOr0QcENqQnqAPRofpvQRhblRk6bFAsn_VXVibw196cCNP3aiC_zV18NyCcCPuPLPkwy Jun 28 20:13:03 volumio.local volumio[1149]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jun 28 20:13:03 volumio.local volumio[1149]: info: New Spotify access token = BQA-SEbQURbX21NV1bihrhh8Jm9AUKHXt8NrTbaFDoXSHq1ALviFpetxrRBogcl0XDyhigflxth369lDSsc8l38CDLBFMnXg2j85IPM2NSBsxfddVi056JjYNx4_L1lOob1QQhsbs4XTq3KFcNY2hM4IUTHydEWnrgpMG6zkzB53O2Wq3Zhi7Tp_b9mU7ob5oCLyJ5UxG23T4UhtEX77dDXoQOr0QcENqQnqAPRofpvQRhblRk6bFAsn_VXVibw196cCNP3aiC_zV18NyCcCPuPLPkwy Jun 28 20:13:03 volumio.local volumio[1149]: info: Spotify credentials grant success - running version from March 24, 2019 Jun 28 20:13:03 volumio.local volumio[1149]: info: Starting Shairport Sync Jun 28 20:13:03 volumio.local volumio[1149]: info: Starting Shairport Sync Jun 28 20:13:03 volumio.local volumio[1149]: info: Starting Shairport Sync Jun 28 20:13:03 volumio.local sudo[1376]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 28 20:13:03 volumio.local sudo[1376]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:03 volumio.local sudo[1378]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 28 20:13:03 volumio.local volumio[1149]: info: CoreCommandRouter::volumioGetState Jun 28 20:13:03 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:03 volumio.local systemd[1]: Started MiniDLNA lightweight DLNA/UPnP-AV server. Jun 28 20:13:03 volumio.local sudo[1378]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:03 volumio.local sudo[1381]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 28 20:13:03 volumio.local sudo[1381]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:03 volumio.local sudo[1372]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:03 volumio.local systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 28 20:13:03 volumio.local volumio[1149]: info: Asound.conf file unchanged, so no further update is needed Jun 28 20:13:03 volumio.local volumio[1149]: info: Output device has changed, restarting MPD Jun 28 20:13:03 volumio.local systemd[1]: shairport-sync.service: Succeeded. Jun 28 20:13:03 volumio.local systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 28 20:13:03 volumio.local systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 28 20:13:03 volumio.local sudo[1376]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:03 volumio.local sudo[1381]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:03 volumio.local sudo[1378]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:03 volumio.local go-librespot[1356]: time="2025-06-28T20:13:03+02:00" level=info msg="running go-librespot 0.2.0" Jun 28 20:13:03 volumio.local volumio[1149]: info: Output device has changed, restarting Shairport Sync Jun 28 20:13:03 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:03 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:03 volumio.local go-librespot[1356]: time="2025-06-28T20:13:03+02:00" level=debug msg="app state loaded" Jun 28 20:13:03 volumio.local go-librespot[1356]: time="2025-06-28T20:13:03+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 28 20:13:03 volumio.local sudo[1388]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 28 20:13:03 volumio.local sudo[1388]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:04 volumio.local volumio[1149]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 28 20:13:04 volumio.local sudo[1386]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 28 20:13:04 volumio.local sudo[1386]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:04 volumio.local sudo[1386]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:04 volumio.local systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Jun 28 20:13:04 volumio.local systemd[1]: mpd.service: Succeeded. Jun 28 20:13:04 volumio.local systemd[1]: Stopped Music Player Daemon. Jun 28 20:13:04 volumio.local volumio[1149]: info: minidlna: systemctl start minidlna.service succeeded. Jun 28 20:13:04 volumio.local systemd[1]: Starting Music Player Daemon... Jun 28 20:13:04 volumio.local volumio[1149]: info: MPD Permissions set Jun 28 20:13:04 volumio.local volumio[1149]: info: Shairport-Sync Started Jun 28 20:13:04 volumio.local volumio[1149]: Error adding Membership: Error: addMembership EINVAL Jun 28 20:13:04 volumio.local volumio[1149]: info: Shairport-Sync Started Jun 28 20:13:04 volumio.local volumio[1149]: info: Shairport-Sync Started Jun 28 20:13:04 volumio.local sudo[1397]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 28 20:13:04 volumio.local sudo[1397]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:04 volumio.local sudo[1397]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:04 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:04 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:04 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:04 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:04 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:04 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:04 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:04 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:04 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:04 volumio.local go-librespot[1356]: time="2025-06-28T20:13:04+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 28 20:13:04 volumio.local go-librespot[1356]: time="2025-06-28T20:13:04+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 28 20:13:04 volumio.local go-librespot[1356]: time="2025-06-28T20:13:04+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 28 20:13:04 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:04 volumio.local go-librespot[1356]: time="2025-06-28T20:13:04+02:00" level=info msg="zeroconf server listening on port 40265" Jun 28 20:13:04 volumio.local volumio[1149]: info: Starting Shairport Sync Jun 28 20:13:04 volumio.local sudo[1411]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 28 20:13:04 volumio.local sudo[1411]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:04 volumio.local volumio[1149]: SPOTIFY: User informations: {"country":"DE","display_name":"roland19300","email":"roland.ruppert@protonmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/roland19300"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/roland19300","id":"roland19300","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee853a1879e1dbb2b0fa2d006b50","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b823a1879e1dbb2b0fa2d006b50","width":64}],"product":"premium","type":"user","uri":"spotify:user:roland19300"} Jun 28 20:13:04 volumio.local volumio[1149]: info: Spotify Successfully logged in Jun 28 20:13:04 volumio.local go-librespot[1356]: time="2025-06-28T20:13:04+02:00" level=debug msg="obtained new client token: AAAlMO/t21v7Wa5/DELkQGPp7eCRMkUxtRF63tP931bi0+VES260RgQCbbPKVs9ATlAp8dsVRT8/grsy9VjeLnvTfdh/QeBYyE9taVdM4uU/enYwg2QZWDylJnm2WfJk7Bj3xdBxY6HWIxpzePXVotUIxtmWCR1jogyiQhzp72ftHuTWp/5N5xhuWjuOwUfoIhKyGEXZmY8hfquCaQAJ2xNY20FoWjxSIWg/Mt2tACX1bbTsBC8jBCTIUA==" Jun 28 20:13:04 volumio.local volumio[1149]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 28 20:13:04 volumio.local volumio[1149]: info: [1751134384282] CoreMusicLibrary::Adding element Spotify Jun 28 20:13:04 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 28 20:13:04 volumio.local volumio[1149]: Cannot find translation for source Spotify Jun 28 20:13:04 volumio.local go-librespot[1356]: time="2025-06-28T20:13:04+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 28 20:13:04 volumio.local go-librespot[1356]: time="2025-06-28T20:13:04+02:00" level=debug msg="completed keyexchange" Jun 28 20:13:04 volumio.local go-librespot[1356]: time="2025-06-28T20:13:04+02:00" level=debug msg="completed challenge" Jun 28 20:13:04 volumio.local systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 28 20:13:04 volumio.local systemd[1]: shairport-sync.service: Succeeded. Jun 28 20:13:04 volumio.local systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 28 20:13:04 volumio.local go-librespot[1356]: time="2025-06-28T20:13:04+02:00" level=info msg="authenticated AP as roland19300" Jun 28 20:13:04 volumio.local systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 28 20:13:04 volumio.local sudo[1411]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:04 volumio.local sudo[1417]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 28 20:13:04 volumio.local sudo[1417]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:04 volumio.local sudo[1417]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:04 volumio.local sudo[1421]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 28 20:13:04 volumio.local sudo[1421]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:04 volumio.local volumio[1149]: info: Shairport-Sync Started Jun 28 20:13:04 volumio.local go-librespot[1356]: time="2025-06-28T20:13:04+02:00" level=info msg="authenticated Login5 as roland19300" Jun 28 20:13:04 volumio.local go-librespot[1356]: time="2025-06-28T20:13:04+02:00" level=debug msg="initializing zeroconf session, username: roland19300" Jun 28 20:13:04 volumio.local sudo[1421]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:04 volumio.local volumio[1149]: verbose: New Socket.io Connection to 192.168.50.222 from 192.168.50.84 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/137.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Jun 28 20:13:04 volumio.local go-librespot[1356]: time="2025-06-28T20:13:04+02:00" level=debug msg="dealer connection opened" Jun 28 20:13:04 volumio.local go-librespot[1356]: time="2025-06-28T20:13:04+02:00" level=trace msg="starting accesspoint recv loop" Jun 28 20:13:04 volumio.local go-librespot[1356]: time="2025-06-28T20:13:04+02:00" level=trace msg="starting dealer recv loop" Jun 28 20:13:04 volumio.local go-librespot[1356]: time="2025-06-28T20:13:04+02:00" level=trace msg="received accesspoint ping" Jun 28 20:13:04 volumio.local go-librespot[1356]: time="2025-06-28T20:13:04+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jun 28 20:13:04 volumio.local go-librespot[1356]: time="2025-06-28T20:13:04+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jun 28 20:13:04 volumio.local go-librespot[1356]: time="2025-06-28T20:13:04+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jun 28 20:13:04 volumio.local go-librespot[1356]: time="2025-06-28T20:13:04+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jun 28 20:13:04 volumio.local go-librespot[1356]: time="2025-06-28T20:13:04+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jun 28 20:13:04 volumio.local go-librespot[1356]: time="2025-06-28T20:13:04+02:00" level=debug msg="received connection id: YjQ0NTRmNjktNTc4Yi00ZWJmLTgyNjAtNTIzNGY0NjdjYjRlK2RlYWxlcit0Y3A6Ly8wYWIxNTFhMy5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArQURERUJFRjEyNzk0RDVFMTM4QTFFNUQ3MTA1NjhFMjBBOTVFNkY2NTg3Q0U5NzcyNUNBMkU0NUUwNkE0QTU4RQ==" Jun 28 20:13:04 volumio.local go-librespot[1356]: time="2025-06-28T20:13:04+02:00" level=trace msg="received accesspoint pong ack" Jun 28 20:13:04 volumio.local volumio[1149]: info: CoreCommandRouter::volumioGetVisibleSources Jun 28 20:13:04 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 28 20:13:04 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 28 20:13:04 volumio.local volumio[1149]: info: CoreCommandRouter::volumioGetState Jun 28 20:13:04 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:04 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 28 20:13:04 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jun 28 20:13:04 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jun 28 20:13:04 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 28 20:13:04 volumio.local go-librespot[1356]: time="2025-06-28T20:13:04+02:00" level=debug msg="put connect state because NEW_DEVICE" Jun 28 20:13:04 volumio.local sudo[1425]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 28 20:13:04 volumio.local sudo[1425]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:04 volumio.local sudo[1425]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:04 volumio.local sudo[1427]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 28 20:13:04 volumio.local sudo[1427]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:04 volumio.local sudo[1427]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:04 volumio.local volumio[1149]: verbose: New Socket.io Connection to 192.168.50.222 from 192.168.50.84 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/137.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Jun 28 20:13:04 volumio.local volumio[1149]: info: CoreCommandRouter::volumioGetState Jun 28 20:13:04 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:04 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 28 20:13:04 volumio.local volumio[1149]: info: CoreCommandRouter::volumioGetVisibleSources Jun 28 20:13:04 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 28 20:13:04 volumio.local volumio[1149]: info: Listing playlists Jun 28 20:13:04 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 28 20:13:04 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jun 28 20:13:04 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jun 28 20:13:04 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 28 20:13:05 volumio.local mpd[1405]: Jun 28 20:13 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 28 20:13:05 volumio.local systemd[1]: Started Music Player Daemon. Jun 28 20:13:05 volumio.local sudo[1317]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:05 volumio.local sudo[1388]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:05 volumio.local sudo[1326]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:05 volumio.local volumio[1149]: error: MPD error: The expression evaluated to a falsy value: Jun 28 20:13:05 volumio.local volumio[1149]: assert.ok(self.idling) Jun 28 20:13:05 volumio.local volumio[1149]: error: The expression evaluated to a falsy value: Jun 28 20:13:05 volumio.local volumio[1149]: assert.ok(self.idling) Jun 28 20:13:05 volumio.local volumio[1149]: info: Completed starting Core Plugins Jun 28 20:13:05 volumio.local volumio[1149]: info: ------------------------------------------- Jun 28 20:13:05 volumio.local volumio[1149]: info: ----- MyVolumio plugins startup ---- Jun 28 20:13:05 volumio.local volumio[1149]: info: ------------------------------------------- Jun 28 20:13:05 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Fetching plans data.... Jun 28 20:13:05 volumio.local volumio[1149]: error: MPD error: The expression evaluated to a falsy value: Jun 28 20:13:05 volumio.local volumio[1149]: assert.ok(self.idling) Jun 28 20:13:05 volumio.local volumio[1149]: error: The expression evaluated to a falsy value: Jun 28 20:13:05 volumio.local volumio[1149]: assert.ok(self.idling) Jun 28 20:13:05 volumio.local volumio[1149]: error: updateQueue error: null Jun 28 20:13:05 volumio.local volumio[1149]: info: MPD running with PID1405 Jun 28 20:13:05 volumio.local volumio[1149]: ,establishing connection Jun 28 20:13:05 volumio.local volumio[1149]: error: updateQueue error: null Jun 28 20:13:05 volumio.local volumio[1149]: info: camilladsp service started and running in background, instance 1 Jun 28 20:13:05 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:05 volumio.local volumio[1149]: info: FusionDsp - AAAAAAAAAAAAAA-> 22050 44100 48000 88200 96000 176400 192000 384000 <-AAAAAAAAAAAAA Jun 28 20:13:05 volumio.local volumio[1149]: info: FusionDsp loaded Jun 28 20:13:05 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 28 20:13:05 volumio.local sudo[1444]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Jun 28 20:13:05 volumio.local sudo[1444]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:05 volumio.local volumio[1149]: info: FusionDsp - Reporting Fusion DSP Enabled Jun 28 20:13:05 volumio.local volumio[1149]: info: Adding Signal Path Element [object Object] Jun 28 20:13:05 volumio.local volumio[1149]: info: Adding fusiondspeq DSP Signal Path Element Jun 28 20:13:05 volumio.local volumio[1149]: info: FusionDsp - ---- installed callbackRead Jun 28 20:13:05 volumio.local volumio[1149]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 28 20:13:05 volumio.local volumio[1149]: error: FusionDsp - WebSocket error: [object Object] Jun 28 20:13:05 volumio.local volumio[1149]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Jun 28 20:13:05 volumio.local systemd[1]: Started FusionDsp Daemon. Jun 28 20:13:05 volumio.local sudo[1444]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:05 volumio.local systemd[1]: systemd-fsckd.service: Succeeded. Jun 28 20:13:06 volumio.local volumio[1149]: info: go-librespot daemon successfully initialized Jun 28 20:13:06 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 28 20:13:06 volumio.local volumio[1149]: info: Received Get System Info Jun 28 20:13:06 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 28 20:13:06 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 28 20:13:06 volumio.local volumio[1149]: info: Discovery: Getting this device information Jun 28 20:13:06 volumio.local volumio[1149]: info: CoreCommandRouter::volumioGetState Jun 28 20:13:06 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:06 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 28 20:13:07 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 28 20:13:07 volumio.local volumio[1149]: info: Received Get System Info Jun 28 20:13:07 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 28 20:13:07 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 28 20:13:07 volumio.local volumio[1149]: info: Discovery: Getting this device information Jun 28 20:13:07 volumio.local volumio[1149]: info: CoreCommandRouter::volumioGetState Jun 28 20:13:07 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:07 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 28 20:13:07 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Jun 28 20:13:07 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Jun 28 20:13:07 volumio.local systemd[1]: systemd-hostnamed.service: Succeeded. Jun 28 20:13:09 volumio.local sudo[1485]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 28 20:13:09 volumio.local sudo[1485]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:09 volumio.local sudo[1485]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:09 volumio.local sudo[1487]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 28 20:13:09 volumio.local sudo[1487]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:09 volumio.local sudo[1487]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:09 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPlay Jun 28 20:13:09 volumio.local volumio[1149]: info: CoreStateMachine::play index undefined Jun 28 20:13:09 volumio.local volumio[1149]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 28 20:13:09 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:09 volumio.local volumio[1149]: info: CoreStateMachine::startPlaybackTimer Jun 28 20:13:09 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:09 volumio.local volumio[1149]: info: [1751134389227] ControllerWebradio::clearAddPlayTrack Jun 28 20:13:09 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand stop Jun 28 20:13:09 volumio.local volumio[1149]: info: sendMpdCommand stop took 3 milliseconds Jun 28 20:13:09 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand clear Jun 28 20:13:09 volumio.local sudo[1491]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jun 28 20:13:09 volumio.local volumio[1149]: info: Jun 28 20:13:09 volumio.local volumio[1149]: ---------------------------- MPD announces system playlist update Jun 28 20:13:09 volumio.local sudo[1491]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:09 volumio.local volumio[1149]: info: Ignoring MPD Status Update Jun 28 20:13:09 volumio.local volumio[1149]: info: sendMpdCommand clear took 4 milliseconds Jun 28 20:13:09 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand load "https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3" Jun 28 20:13:09 volumio.local volumio[1149]: info: Jun 28 20:13:09 volumio.local volumio[1149]: ---------------------------- MPD announces system playlist update Jun 28 20:13:09 volumio.local volumio[1149]: info: Ignoring MPD Status Update Jun 28 20:13:09 volumio.local volumio[1149]: info: Jun 28 20:13:09 volumio.local volumio[1149]: ---------------------------- MPD announces system playlist update Jun 28 20:13:09 volumio.local volumio[1149]: info: Ignoring MPD Status Update Jun 28 20:13:09 volumio.local volumio[1149]: info: Jun 28 20:13:09 volumio.local volumio[1149]: ---------------------------- MPD announces system playlist update Jun 28 20:13:09 volumio.local volumio[1149]: info: Ignoring MPD Status Update Jun 28 20:13:09 volumio.local volumio[1149]: error: updateQueue error: null Jun 28 20:13:09 volumio.local volumio[1149]: info: ------------------------------ 9ms Jun 28 20:13:09 volumio.local systemd[1]: Started UPnP Renderer front-end to MPD. Jun 28 20:13:09 volumio.local sudo[1491]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:09 volumio.local volumio[1149]: info: Upmpdcli Daemon Started Jun 28 20:13:09 volumio.local volumio[1149]: info: Initializing connection to go-librespot Websocket Jun 28 20:13:09 volumio.local go-librespot[1356]: time="2025-06-28T20:13:09+02:00" level=debug msg="new websocket client" Jun 28 20:13:09 volumio.local volumio[1149]: info: Connection to go-librespot Websocket established Jun 28 20:13:11 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand add "https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3" Jun 28 20:13:11 volumio.local volumio[1149]: Upnp client error: Error: This socket has been ended by the other party Jun 28 20:13:11 volumio.local volumio[1149]: error: updateQueue error: null Jun 28 20:13:11 volumio.local volumio[1149]: error: updateQueue error: null Jun 28 20:13:11 volumio.local volumio[1149]: error: updateQueue error: null Jun 28 20:13:11 volumio.local volumio[1149]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jun 28 20:13:11 volumio.local volumio[1149]: info: ------------------------------ 2503ms Jun 28 20:13:11 volumio.local volumio[1149]: info: ------------------------------ 2501ms Jun 28 20:13:11 volumio.local volumio[1149]: info: ------------------------------ 2500ms Jun 28 20:13:11 volumio.local volumio[1149]: info: Jun 28 20:13:11 volumio.local volumio[1149]: ---------------------------- MPD announces system playlist update Jun 28 20:13:11 volumio.local volumio[1149]: info: Ignoring MPD Status Update Jun 28 20:13:11 volumio.local volumio[1149]: info: sendMpdCommand add "https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3" took 157 milliseconds Jun 28 20:13:11 volumio.local volumio[1149]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 28 20:13:11 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand play Jun 28 20:13:11 volumio.local volumio[1149]: info: Jun 28 20:13:11 volumio.local volumio[1149]: ---------------------------- MPD announces system playlist update Jun 28 20:13:11 volumio.local volumio[1149]: info: Ignoring MPD Status Update Jun 28 20:13:11 volumio.local volumio[1149]: info: Jun 28 20:13:11 volumio.local volumio[1149]: ---------------------------- MPD announces system playlist update Jun 28 20:13:11 volumio.local volumio[1149]: info: Ignoring MPD Status Update Jun 28 20:13:11 volumio.local volumio[1149]: info: Jun 28 20:13:11 volumio.local volumio[1149]: ---------------------------- MPD announces system playlist update Jun 28 20:13:11 volumio.local volumio[1149]: info: Ignoring MPD Status Update Jun 28 20:13:11 volumio.local volumio[1149]: info: ------------------------------ 6ms Jun 28 20:13:11 volumio.local volumio[1149]: info: sendMpdCommand play took 4 milliseconds Jun 28 20:13:11 volumio.local volumio[1149]: info: ------------------------------ 4ms Jun 28 20:13:11 volumio.local volumio[1149]: info: ------------------------------ 3ms Jun 28 20:13:11 volumio.local volumio[1149]: info: ------------------------------ 2ms Jun 28 20:13:12 volumio.local volumio[1149]: info: Getting Spotify volume Jun 28 20:13:12 volumio.local volumio[1149]: info: Spotify volume: 100 Jun 28 20:13:12 volumio.local volumio[1149]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Jun 28 20:13:12 volumio.local volumio[1149]: info: CoreCommandRouter::volumioGetState Jun 28 20:13:12 volumio.local volumio[1149]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Jun 28 20:13:12 volumio.local volumio[1149]: SPOTIFY: SPOTIFY VOLUME 100 Jun 28 20:13:12 volumio.local volumio[1149]: SPOTIFY: VOLUMIO VOLUME 75 Jun 28 20:13:12 volumio.local volumio[1149]: SPOTIFY: DELTA VOLUME ENOUGH: true Jun 28 20:13:12 volumio.local volumio[1149]: info: Setting Spotify Volume from Volumio: 75 Jun 28 20:13:13 volumio.local volumio[1494]: Generating RSA private key, 4096 bit long modulus (2 primes) Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jun 28 20:13:13 volumio.local volumio[1149]: info: Adding plugin bluetooth to MyMusic Plugins Jun 28 20:13:13 volumio.local volumio[1149]: info: Adding plugin multiroom to MyMusic Plugins Jun 28 20:13:13 volumio.local volumio[1149]: info: Adding plugin metavolumio to MyMusic Plugins Jun 28 20:13:13 volumio.local volumio[1149]: info: Adding plugin cd_controller to MyMusic Plugins Jun 28 20:13:13 volumio.local volumio[1149]: info: Adding plugin qobuzconnect to MyMusic Plugins Jun 28 20:13:13 volumio.local volumio[1149]: info: Adding plugin smart_inputs to MyMusic Plugins Jun 28 20:13:13 volumio.local volumio[1149]: info: Adding plugin tidalconnect to MyMusic Plugins Jun 28 20:13:13 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jun 28 20:13:14 volumio.local volumio[1149]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jun 28 20:13:14 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jun 28 20:13:14 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:14 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:14 volumio.local volumio[1149]: info: Starting MyVolumio Remote Streaming Endpoints Jun 28 20:13:14 volumio.local volumio[1149]: info: MyVolumio login type: Token Jun 28 20:13:14 volumio.local volumio[1149]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jun 28 20:13:14 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jun 28 20:13:15 volumio.local volumio[1149]: info: Starting Streaming Service Transparent Proxy Jun 28 20:13:15 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jun 28 20:13:15 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jun 28 20:13:15 volumio.local volumio[1149]: info: Streaming services startup Jun 28 20:13:15 volumio.local volumio[1149]: info: Starting Streaming Daemon Jun 28 20:13:15 volumio.local sudo[1541]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jun 28 20:13:15 volumio.local sudo[1541]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:15 volumio.local sudo[1541]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:15 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jun 28 20:13:15 volumio.local volumio[1149]: SPOTIFY: SETTING SPOTIFY VOLUME 75 Jun 28 20:13:15 volumio.local volumio[1149]: info: Sending Spotify command with payload to local API: /player/volume Jun 28 20:13:15 volumio.local volumio[1149]: info: Jun 28 20:13:15 volumio.local volumio[1149]: ---------------------------- MPD announces state update: player Jun 28 20:13:15 volumio.local volumio[1149]: info: ControllerMpd::getState Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand status Jun 28 20:13:15 volumio.local volumio[1149]: info: Jun 28 20:13:15 volumio.local volumio[1149]: ---------------------------- MPD announces state update: player Jun 28 20:13:15 volumio.local volumio[1149]: info: ControllerMpd::getState Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand status Jun 28 20:13:15 volumio.local volumio[1149]: info: Jun 28 20:13:15 volumio.local volumio[1149]: ---------------------------- MPD announces state update: player Jun 28 20:13:15 volumio.local volumio[1149]: info: ControllerMpd::getState Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand status Jun 28 20:13:15 volumio.local volumio[1149]: info: Jun 28 20:13:15 volumio.local volumio[1149]: ---------------------------- MPD announces state update: player Jun 28 20:13:15 volumio.local volumio[1149]: info: ControllerMpd::getState Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand status Jun 28 20:13:15 volumio.local volumio[1149]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jun 28 20:13:15 volumio.local volumio[1149]: info: FusionDsp - ---- read samplerate from file: 44100 Jun 28 20:13:15 volumio.local volumio[1149]: info: camilladsp stopping service pid 1440... Jun 28 20:13:15 volumio.local volumio[1149]: info: camilladsp service terminated, instance 1 Jun 28 20:13:15 volumio.local volumio[1149]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 28 20:13:15 volumio.local volumio[1149]: info: camilladsp service started and running in background, instance 1 Jun 28 20:13:15 volumio.local go-librespot[1356]: time="2025-06-28T20:13:15+02:00" level=debug msg="update volume to 49151/65535" Jun 28 20:13:15 volumio.local volumio[1149]: error: Cannot start Volumio Streaming Daemon Jun 28 20:13:15 volumio.local volumio[1149]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jun 28 20:13:15 volumio.local volumio[1149]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jun 28 20:13:15 volumio.local volumio[1149]: info: Jun 28 20:13:15 volumio.local volumio[1149]: ---------------------------- MPD announces system playlist update Jun 28 20:13:15 volumio.local volumio[1149]: info: Ignoring MPD Status Update Jun 28 20:13:15 volumio.local volumio[1149]: info: Jun 28 20:13:15 volumio.local volumio[1149]: ---------------------------- MPD announces state update: player Jun 28 20:13:15 volumio.local volumio[1149]: info: ControllerMpd::getState Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand status Jun 28 20:13:15 volumio.local volumio[1149]: info: sendMpdCommand status took 57 milliseconds Jun 28 20:13:15 volumio.local volumio[1149]: info: sendMpdCommand status took 49 milliseconds Jun 28 20:13:15 volumio.local volumio[1149]: info: sendMpdCommand status took 49 milliseconds Jun 28 20:13:15 volumio.local volumio[1149]: info: sendMpdCommand status took 48 milliseconds Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::parseState Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::parseState Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::parseState Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::parseState Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 28 20:13:15 volumio.local volumio[1149]: info: Jun 28 20:13:15 volumio.local volumio[1149]: ---------------------------- MPD announces system playlist update Jun 28 20:13:15 volumio.local volumio[1149]: info: Ignoring MPD Status Update Jun 28 20:13:15 volumio.local volumio[1149]: info: Jun 28 20:13:15 volumio.local volumio[1149]: ---------------------------- MPD announces state update: player Jun 28 20:13:15 volumio.local volumio[1149]: info: ControllerMpd::getState Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand status Jun 28 20:13:15 volumio.local volumio[1149]: info: Jun 28 20:13:15 volumio.local volumio[1149]: ---------------------------- MPD announces system playlist update Jun 28 20:13:15 volumio.local volumio[1149]: info: Ignoring MPD Status Update Jun 28 20:13:15 volumio.local volumio[1149]: info: Jun 28 20:13:15 volumio.local volumio[1149]: ---------------------------- MPD announces state update: player Jun 28 20:13:15 volumio.local volumio[1149]: info: ControllerMpd::getState Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand status Jun 28 20:13:15 volumio.local volumio[1149]: info: Jun 28 20:13:15 volumio.local volumio[1149]: ---------------------------- MPD announces system playlist update Jun 28 20:13:15 volumio.local volumio[1149]: info: Ignoring MPD Status Update Jun 28 20:13:15 volumio.local volumio[1149]: info: Jun 28 20:13:15 volumio.local volumio[1149]: ---------------------------- MPD announces state update: player Jun 28 20:13:15 volumio.local volumio[1149]: info: ControllerMpd::getState Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand status Jun 28 20:13:15 volumio.local volumio[1149]: info: ------------------------------ 36ms Jun 28 20:13:15 volumio.local volumio[1149]: info: sendMpdCommand status took 36 milliseconds Jun 28 20:13:15 volumio.local volumio[1149]: info: sendMpdCommand playlistinfo took 32 milliseconds Jun 28 20:13:15 volumio.local volumio[1149]: info: sendMpdCommand playlistinfo took 31 milliseconds Jun 28 20:13:15 volumio.local volumio[1149]: info: ------------------------------ 30ms Jun 28 20:13:15 volumio.local volumio[1149]: info: sendMpdCommand status took 30 milliseconds Jun 28 20:13:15 volumio.local volumio[1149]: info: ------------------------------ 29ms Jun 28 20:13:15 volumio.local volumio[1149]: info: sendMpdCommand status took 28 milliseconds Jun 28 20:13:15 volumio.local volumio[1149]: info: ------------------------------ 28ms Jun 28 20:13:15 volumio.local volumio[1149]: info: sendMpdCommand status took 28 milliseconds Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::parseState Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::parseTrackInfo Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::parseTrackInfo Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::parseTrackInfo Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::parseTrackInfo Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::parseState Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::parseState Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::parseState Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 28 20:13:15 volumio.local volumio[1149]: info: ControllerMpd::pushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreCommandRouter::servicePushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:15 volumio.local volumio[1149]: verbose: STATE SERVICE {"status":"play","position":0,"seek":3484,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Absolut Radio AI","artist":"Absolut AI","album":null,"uri":"https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3","trackType":""} Jun 28 20:13:15 volumio.local volumio[1149]: verbose: CURRENT POSITION 0 Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::syncState stateService play Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::syncState currentStatus stop Jun 28 20:13:15 volumio.local volumio[1149]: info: ControllerMpd::pushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreCommandRouter::servicePushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:15 volumio.local volumio[1149]: verbose: STATE SERVICE {"status":"play","position":0,"seek":3484,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Absolut Radio AI","artist":"Absolut AI","album":null,"uri":"https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3","trackType":""} Jun 28 20:13:15 volumio.local volumio[1149]: verbose: CURRENT POSITION 0 Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::syncState stateService play Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::syncState currentStatus play Jun 28 20:13:15 volumio.local volumio[1149]: info: Received an update from plugin. extracting info from payload Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::pushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::pushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPushState Jun 28 20:13:15 volumio.local volumio[1149]: info: ControllerMpd::pushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreCommandRouter::servicePushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:15 volumio.local volumio[1149]: verbose: STATE SERVICE {"status":"play","position":0,"seek":3484,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Absolut Radio AI","artist":"Absolut AI","album":null,"uri":"https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3","trackType":""} Jun 28 20:13:15 volumio.local volumio[1149]: verbose: CURRENT POSITION 0 Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::syncState stateService play Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::syncState currentStatus play Jun 28 20:13:15 volumio.local volumio[1149]: info: Received an update from plugin. extracting info from payload Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::pushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::pushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPushState Jun 28 20:13:15 volumio.local volumio[1149]: info: ControllerMpd::pushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreCommandRouter::servicePushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:15 volumio.local volumio[1149]: verbose: STATE SERVICE {"status":"play","position":0,"seek":3484,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Absolut Radio AI","artist":"Absolut AI","album":null,"uri":"https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3","trackType":""} Jun 28 20:13:15 volumio.local volumio[1149]: verbose: CURRENT POSITION 0 Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::syncState stateService play Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::syncState currentStatus play Jun 28 20:13:15 volumio.local volumio[1149]: info: Received an update from plugin. extracting info from payload Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::pushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::pushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPushState Jun 28 20:13:15 volumio.local volumio[1149]: info: ------------------------------ 129ms Jun 28 20:13:15 volumio.local volumio[1149]: info: ------------------------------ 162ms Jun 28 20:13:15 volumio.local volumio[1149]: info: ------------------------------ 156ms Jun 28 20:13:15 volumio.local volumio[1149]: info: ------------------------------ 154ms Jun 28 20:13:15 volumio.local volumio[1149]: info: sendMpdCommand playlistinfo took 85 milliseconds Jun 28 20:13:15 volumio.local volumio[1149]: info: sendMpdCommand playlistinfo took 83 milliseconds Jun 28 20:13:15 volumio.local volumio[1149]: info: sendMpdCommand playlistinfo took 82 milliseconds Jun 28 20:13:15 volumio.local volumio[1149]: verbose: ControllerMpd::parseTrackInfo Jun 28 20:13:15 volumio.local volumio[1149]: info: ControllerMpd::pushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreCommandRouter::servicePushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:15 volumio.local volumio[1149]: verbose: STATE SERVICE {"status":"play","position":0,"seek":3484,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Absolut Radio AI","artist":"Absolut AI","album":null,"uri":"https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3","trackType":""} Jun 28 20:13:15 volumio.local volumio[1149]: verbose: CURRENT POSITION 0 Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::syncState stateService play Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::syncState currentStatus play Jun 28 20:13:15 volumio.local volumio[1149]: info: Received an update from plugin. extracting info from payload Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::pushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::pushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPushState Jun 28 20:13:15 volumio.local volumio[1149]: info: ControllerMpd::pushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreCommandRouter::servicePushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:15 volumio.local volumio[1149]: verbose: STATE SERVICE {"status":"play","position":0,"seek":3484,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Absolut Radio AI","artist":"Absolut AI","album":null,"uri":"https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3","trackType":""} Jun 28 20:13:15 volumio.local volumio[1149]: verbose: CURRENT POSITION 0 Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::syncState stateService play Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::syncState currentStatus play Jun 28 20:13:15 volumio.local volumio[1149]: info: Received an update from plugin. extracting info from payload Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::pushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::pushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPushState Jun 28 20:13:15 volumio.local volumio[1149]: info: ControllerMpd::pushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreCommandRouter::servicePushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:15 volumio.local volumio[1149]: verbose: STATE SERVICE {"status":"play","position":0,"seek":3484,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Absolut Radio AI","artist":"Absolut AI","album":null,"uri":"https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3","trackType":""} Jun 28 20:13:15 volumio.local volumio[1149]: verbose: CURRENT POSITION 0 Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::syncState stateService play Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::syncState currentStatus play Jun 28 20:13:15 volumio.local volumio[1149]: info: Received an update from plugin. extracting info from payload Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::pushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::pushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPushState Jun 28 20:13:15 volumio.local volumio[1149]: info: ControllerMpd::pushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreCommandRouter::servicePushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:15 volumio.local volumio[1149]: verbose: STATE SERVICE {"status":"play","position":0,"seek":3484,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Absolut Radio AI","artist":"Absolut AI","album":null,"uri":"https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3","trackType":""} Jun 28 20:13:15 volumio.local volumio[1149]: verbose: CURRENT POSITION 0 Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::syncState stateService play Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::syncState currentStatus play Jun 28 20:13:15 volumio.local volumio[1149]: info: Received an update from plugin. extracting info from payload Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::pushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreStateMachine::pushState Jun 28 20:13:15 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPushState Jun 28 20:13:15 volumio.local volumio[1149]: info: ------------------------------ 184ms Jun 28 20:13:15 volumio.local volumio[1149]: info: ------------------------------ 177ms Jun 28 20:13:15 volumio.local volumio[1149]: info: ------------------------------ 176ms Jun 28 20:13:15 volumio.local volumio[1149]: info: ------------------------------ 175ms Jun 28 20:13:15 volumio.local volumio[1149]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Jun 28 20:13:15 volumio.local volumio[1149]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Jun 28 20:13:15 volumio.local volumio[1149]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Jun 28 20:13:15 volumio.local volumio[1149]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Jun 28 20:13:15 volumio.local volumio[1149]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Jun 28 20:13:15 volumio.local volumio[1149]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Jun 28 20:13:15 volumio.local volumio[1149]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Jun 28 20:13:15 volumio.local volumio[1149]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Jun 28 20:13:15 volumio.local volumio[1149]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Jun 28 20:13:15 volumio.local volumio[1149]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Jun 28 20:13:15 volumio.local volumio[1149]: error: MyVolumio Custom Token format not valid, refreshing it Jun 28 20:13:16 volumio.local volumio[1149]: STREAMING PROXY: Starting server on port 3245 Jun 28 20:13:16 volumio.local volumio[1149]: Node JS runtime: 14 Jun 28 20:13:16 volumio.local go-librespot[1356]: time="2025-06-28T20:13:16+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Jun 28 20:13:16 volumio.local go-librespot[1356]: time="2025-06-28T20:13:16+02:00" level=trace msg="emitting websocket event: volume" Jun 28 20:13:16 volumio.local volumio[1149]: SPOTIFY: received: {"type":"volume","data":{"value":75,"max":100}} Jun 28 20:13:16 volumio.local volumio[1149]: SPOTIFY: RECEIVED SPOTIFY VOLUME 75 Jun 28 20:13:16 volumio.local volumio[1149]: info: MyVolumio login type: Token Jun 28 20:13:16 volumio.local volumio[1149]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jun 28 20:13:17 volumio.local systemd[1]: systemd-timedated.service: Succeeded. Jun 28 20:13:18 volumio.local volumio[1149]: info: MyVolumio token set successfully Jun 28 20:13:18 volumio.local volumio[1149]: info: MYVOLUMIO: Adding device Jun 28 20:13:18 volumio.local volumio[1149]: info: MYVOLUMIO: Evaluating Server Jun 28 20:13:18 volumio.local volumio[1149]: info: MyVolumio Plan changed: premium Jun 28 20:13:18 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Jun 28 20:13:18 volumio.local volumio[1149]: info: Removing browser output: myVolumio user plan is not superstar Jun 28 20:13:18 volumio.local volumio[1149]: info: Removing audio output: Jun 28 20:13:18 volumio.local volumio[1149]: info: MYVOLUMIO: Adding device Jun 28 20:13:18 volumio.local volumio[1149]: info: MYVOLUMIO: Evaluating Server Jun 28 20:13:18 volumio.local volumio[1149]: info: Remote config written successfully Jun 28 20:13:18 volumio.local volumio[1149]: info: Starting Tunnel 1 Jun 28 20:13:18 volumio.local volumio[1149]: info: Starting Tunnel Connection Checker Jun 28 20:13:18 volumio.local volumio[1149]: info: Completed starting MyVolumio Plugin Jun 28 20:13:18 volumio.local volumio[1149]: info: MYVolumio Device enabled Jun 28 20:13:18 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Jun 28 20:13:18 volumio.local volumio[1149]: info: MyVolumio status changed Jun 28 20:13:18 volumio.local volumio[1149]: info: Streaming services startup Jun 28 20:13:18 volumio.local volumio[1149]: info: Starting Streaming Daemon Jun 28 20:13:18 volumio.local volumio[1149]: info: Setting Geolocation for MyVolumio to eu10 Jun 28 20:13:18 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:18 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:18 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:18 volumio.local sudo[1606]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jun 28 20:13:18 volumio.local sudo[1606]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:18 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Jun 28 20:13:18 volumio.local volumio[1149]: error: [MyVolumio PluginManager] Cache data is invalid! Jun 28 20:13:18 volumio.local sudo[1606]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:18 volumio.local volumio[1149]: error: Cannot start Volumio Streaming Daemon Jun 28 20:13:18 volumio.local volumio[1149]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jun 28 20:13:18 volumio.local volumio[1149]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jun 28 20:13:19 volumio.local volumio[1149]: info: Setting Geolocation for MyVolumio to eu6 Jun 28 20:13:19 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:19 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:19 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:19 volumio.local volumio[1149]: info: Successfully Added MyVolumio device Jun 28 20:13:19 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Jun 28 20:13:19 volumio.local volumio[1149]: info: [1751134399590] Starting BluetoothController Jun 28 20:13:19 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Jun 28 20:13:20 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Jun 28 20:13:20 volumio.local sudo[1628]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Jun 28 20:13:20 volumio.local sudo[1628]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:20 volumio.local sudo[1628]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:21 volumio.local volumio[1149]: info: MRS: MultiRoom plugin initialized Jun 28 20:13:21 volumio.local volumio[1149]: info: MRS: STOPPING SNAPCLIENT Jun 28 20:13:21 volumio.local volumio[1149]: info: MRS: Snap server stop Jun 28 20:13:21 volumio.local sudo[1644]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Jun 28 20:13:21 volumio.local sudo[1644]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:21 volumio.local volumio[1149]: info: MRS: STOPPING volumioStreaming Jun 28 20:13:21 volumio.local sudo[1647]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Jun 28 20:13:21 volumio.local sudo[1647]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:21 volumio.local sudo[1650]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Jun 28 20:13:21 volumio.local sudo[1650]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:21 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Jun 28 20:13:21 volumio.local sudo[1644]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:21 volumio.local sudo[1652]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Jun 28 20:13:21 volumio.local sudo[1652]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:21 volumio.local sudo[1652]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:21 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Jun 28 20:13:21 volumio.local sudo[1647]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:21 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Jun 28 20:13:21 volumio.local sudo[1650]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:21 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Jun 28 20:13:21 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Jun 28 20:13:21 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Jun 28 20:13:21 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Jun 28 20:13:21 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Jun 28 20:13:21 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Jun 28 20:13:21 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Jun 28 20:13:21 volumio.local volumio[1149]: info: Preparing to generate the ALSA configuration file Jun 28 20:13:21 volumio.local volumio[1149]: info: Updating MyVolumio device info Jun 28 20:13:21 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:21 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:21 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:21 volumio.local volumio[1149]: info: Updating MyVolumio device info Jun 28 20:13:21 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:21 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:21 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:21 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Jun 28 20:13:21 volumio.local volumio[1149]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jun 28 20:13:21 volumio.local volumio[1149]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Jun 28 20:13:21 volumio.local volumio[1149]: info: Reading ALSA contributions from plugins. Jun 28 20:13:21 volumio.local volumio[1149]: info: Successfully Added MyVolumio device Jun 28 20:13:21 volumio.local volumio[1149]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 28 20:13:21 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jun 28 20:13:21 volumio.local volumio[1149]: info: MRS: Removed streaming files Jun 28 20:13:21 volumio.local volumio[1149]: info: MRS: volumioStreaming STOPPED Jun 28 20:13:21 volumio.local volumio[1149]: info: MRS: SNAPSERVER STOPPED Jun 28 20:13:21 volumio.local volumio[1149]: info: MRS: SNAPCLIENT STOPPED Jun 28 20:13:21 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jun 28 20:13:21 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jun 28 20:13:21 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Jun 28 20:13:21 volumio.local volumio[1149]: info: Asound.conf file written Jun 28 20:13:21 volumio.local sudo[1672]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Jun 28 20:13:21 volumio.local sudo[1672]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:21 volumio.local sudo[1672]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:21 volumio.local volumio[1149]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:Max Overclock PLL:0' : Device or resource busy Jun 28 20:13:21 volumio.local volumio[1149]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:Max Overclock DSP:0' : Device or resource busy Jun 28 20:13:21 volumio.local volumio[1149]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:Max Overclock DAC:0' : Device or resource busy Jun 28 20:13:21 volumio.local volumio[1149]: info: Output device has changed, restarting MPD Jun 28 20:13:21 volumio.local sudo[1677]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 28 20:13:21 volumio.local sudo[1677]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:21 volumio.local volumio[1149]: info: Output device has changed, restarting Shairport Sync Jun 28 20:13:21 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:21 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:21 volumio.local sudo[1677]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:21 volumio.local sudo[1680]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 28 20:13:21 volumio.local sudo[1680]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:21 volumio.local systemd[1]: Stopping Music Player Daemon... Jun 28 20:13:21 volumio.local volumio[1149]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 28 20:13:21 volumio.local volumio[1149]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Jun 28 20:13:21 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:21 volumio.local systemd[1]: mpd.service: Succeeded. Jun 28 20:13:21 volumio.local systemd[1]: Stopped Music Player Daemon. Jun 28 20:13:21 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Jun 28 20:13:21 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 28 20:13:21 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Jun 28 20:13:21 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Jun 28 20:13:21 volumio.local volumio[1149]: info: MRS: Pushing multiroomSync output for this device Jun 28 20:13:21 volumio.local volumio[1149]: info: MRS: Pushing multiroomSync output Jun 28 20:13:21 volumio.local volumio[1149]: info: Adding audio output: Jun 28 20:13:21 volumio.local systemd[1]: Starting Music Player Daemon... Jun 28 20:13:21 volumio.local sudo[1689]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name volumio.local Jun 28 20:13:21 volumio.local sudo[1689]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:21 volumio.local sudo[1689]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:21 volumio.local volumio[1149]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Jun 28 20:13:21 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:21 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Jun 28 20:13:21 volumio.local volumio[1149]: info: Adding METAVOLUMIO REST API Endpoints Jun 28 20:13:21 volumio.local volumio[1149]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Jun 28 20:13:21 volumio.local volumio[1149]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Jun 28 20:13:21 volumio.local volumio[1149]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Jun 28 20:13:21 volumio.local volumio[1149]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Jun 28 20:13:21 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Jun 28 20:13:21 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Jun 28 20:13:22 volumio.local volumio[1149]: info: Preparing CD Folders Jun 28 20:13:22 volumio.local volumio[1149]: info: Adding CD REST API Endpoints Jun 28 20:13:22 volumio.local volumio[1149]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Jun 28 20:13:22 volumio.local volumio[1149]: info: Starting UDEV Watcher for CD Jun 28 20:13:22 volumio.local volumio[1149]: info: Detecting CD presence with UDEV Jun 28 20:13:22 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Jun 28 20:13:22 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Jun 28 20:13:22 volumio.local volumio[1149]: info: Adding inputs REST Endpoints Jun 28 20:13:22 volumio.local volumio[1149]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Jun 28 20:13:22 volumio.local volumio[1149]: info: Scanning Audio Inputs Jun 28 20:13:22 volumio.local sudo[1687]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 28 20:13:22 volumio.local sudo[1687]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:22 volumio.local sudo[1687]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:22 volumio.local volumio[1149]: info: Checking against Known Cards name Jun 28 20:13:22 volumio.local volumio[1149]: info: Adding Server instance for streaming Jun 28 20:13:22 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Jun 28 20:13:22 volumio.local volumio[1149]: error: Hi Res Audio Failed Login: Missing Login Data Jun 28 20:13:22 volumio.local volumio[1149]: info: Adding HIGHRESAUDIO REST API Endpoints Jun 28 20:13:22 volumio.local volumio[1149]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Jun 28 20:13:22 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Jun 28 20:13:22 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Jun 28 20:13:22 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Jun 28 20:13:22 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Plugin tidalconnect disabled by user. Not starting Jun 28 20:13:22 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Jun 28 20:13:22 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Plugin qobuzconnect disabled by user. Not starting Jun 28 20:13:22 volumio.local volumio[1149]: info: Stopping AccessToken refresher cron Jun 28 20:13:22 volumio.local volumio[1149]: info: AccessToken refresher cron started Jun 28 20:13:22 volumio.local volumio[1149]: info: Stopping AccessToken refresher cron for QOBUZ Jun 28 20:13:22 volumio.local volumio[1149]: info: AccessToken refresher cron started for QOBUZ Jun 28 20:13:22 volumio.local volumio[1149]: info: Adding TIDAL REST API Endpoints Jun 28 20:13:22 volumio.local volumio[1149]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Jun 28 20:13:22 volumio.local volumio[1149]: info: Adding QOBUZ REST API Endpoints Jun 28 20:13:22 volumio.local volumio[1149]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Jun 28 20:13:22 volumio.local volumio[1149]: info: Received Get System Version Jun 28 20:13:22 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 28 20:13:22 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: appearance , getBackgrounds Jun 28 20:13:22 volumio.local volumio[1149]: info: Successfully Updated MyVolumio device Jun 28 20:13:22 volumio.local volumio[1149]: info: Successfully Updated MyVolumio device Jun 28 20:13:22 volumio.local volumio[1149]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined Jun 28 20:13:22 volumio.local volumio[1149]: info: Bluetooth name changed to volumio.local Jun 28 20:13:22 volumio.local volumio[1149]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined Jun 28 20:13:22 volumio.local volumio[1149]: info: MPD Permissions set Jun 28 20:13:22 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:22 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:22 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:22 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:22 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:22 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:22 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:22 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:22 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:22 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:22 volumio.local volumio[1149]: [Metrics] CommandRouter: 25s 139.84ms Jun 28 20:13:22 volumio.local volumio[1149]: info: CoreCommandRouter::volumiosetStartupVolume Jun 28 20:13:22 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:22 volumio.local volumio[1149]: info: VolumeController:: Setting startup Volume 75 Jun 28 20:13:22 volumio.local volumio[1149]: info: VolumeController::SetAlsaVolume75 Jun 28 20:13:22 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:22 volumio.local volumio[1149]: info: CoreCommandRouter::Close All Modals sent Jun 28 20:13:22 volumio.local volumio[1149]: info: CoreStateMachine::pushState Jun 28 20:13:22 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 28 20:13:22 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPushState Jun 28 20:13:22 volumio.local volumio[1149]: info: MRS: Pushing multiroomSync output update for this device Jun 28 20:13:22 volumio.local volumio[1149]: info: MRS: Pushing multiroomSync output Jun 28 20:13:22 volumio.local volumio[1149]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Jun 28 20:13:22 volumio.local volumio[1149]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jun 28 20:13:22 volumio.local volumio[1149]: info: FusionDsp - ---- read samplerate from file: 44100 Jun 28 20:13:22 volumio.local volumio[1149]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 28 20:13:22 volumio.local volumio[1149]: info: Starting Shairport Sync Jun 28 20:13:22 volumio.local sudo[1707]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 28 20:13:22 volumio.local sudo[1707]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:22 volumio.local systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 28 20:13:22 volumio.local systemd[1]: shairport-sync.service: Succeeded. Jun 28 20:13:22 volumio.local systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 28 20:13:22 volumio.local volumio[1149]: info: Adding audio output: Jun 28 20:13:22 volumio.local systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 28 20:13:22 volumio.local sudo[1707]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:22 volumio.local volumio[1149]: info: Adding audio output: Jun 28 20:13:22 volumio.local volumio[1149]: info: Shairport-Sync Started Jun 28 20:13:22 volumio.local volumio[1149]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 28 20:13:22 volumio.local volumio[1149]: error: Upnp client error: Error: This socket has been ended by the other party Jun 28 20:13:22 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 28 20:13:22 volumio.local volumio[1149]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jun 28 20:13:22 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jun 28 20:13:22 volumio.local volumio[1149]: info: Received Get System Version Jun 28 20:13:22 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 28 20:13:22 volumio.local volumio[1149]: info: Received Get System Info Jun 28 20:13:22 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 28 20:13:22 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 28 20:13:22 volumio.local volumio[1149]: info: Discovery: Getting this device information Jun 28 20:13:22 volumio.local volumio[1149]: info: CoreCommandRouter::volumioGetState Jun 28 20:13:22 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 28 20:13:22 volumio.local mpd[1697]: Jun 28 20:13 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 28 20:13:22 volumio.local systemd[1]: Started Music Player Daemon. Jun 28 20:13:22 volumio.local sudo[1680]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:22 volumio.local volumio[1149]: error: updateQueue error: null Jun 28 20:13:23 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jun 28 20:13:23 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 28 20:13:23 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jun 28 20:13:24 volumio.local sudo[1727]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Jun 28 20:13:24 volumio.local sudo[1727]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:24 volumio.local sudo[1727]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:24 volumio.local systemd[1]: Started MyVolumio SSH Tunnel. Jun 28 20:13:24 volumio.local volumio[1149]: info: Remote SSH Started Jun 28 20:13:24 volumio.local autossh[1730]: port set to 0, monitoring disabled Jun 28 20:13:24 volumio.local autossh[1730]: starting ssh (count 1) Jun 28 20:13:24 volumio.local autossh[1730]: ssh child pid is 1733 Jun 28 20:13:24 volumio.local volumiossh-tunnel[1729]: Warning: Permanently added '[eu6.myvolumio.org]:2222,[207.154.233.230]:2222' (RSA) to the list of known hosts. Jun 28 20:13:24 volumio.local volumio[1149]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jun 28 20:13:24 volumio.local volumio[1149]: info: CoreCommandRouter::volumioGetState Jun 28 20:13:24 volumio.local sudo[1737]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Jun 28 20:13:24 volumio.local sudo[1737]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:25 volumio.local systemd[1]: Started Volumio Bluetooth Module. Jun 28 20:13:25 volumio.local sudo[1737]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:25 volumio.local volumio[1149]: info: Volumio BT Module successfully started Jun 28 20:13:25 volumio.local sudo[1740]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* Jun 28 20:13:25 volumio.local sudo[1740]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:25 volumio.local volumiobt[1739]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory Jun 28 20:13:25 volumio.local sudo[1740]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:26 volumio.local sudo[1745]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio Jun 28 20:13:26 volumio.local sudo[1745]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:26 volumio.local volumiobt[1739]: pulseaudio: no process found Jun 28 20:13:26 volumio.local sudo[1745]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:26 volumio.local dbus-daemon[642]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.22' (uid=1000 pid=1749 comm="/usr/bin/pulseaudio --high-priority=true ") Jun 28 20:13:26 volumio.local systemd[1]: Starting RealtimeKit Scheduling Policy Service... Jun 28 20:13:26 volumio.local volumio[1149]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 28 20:13:26 volumio.local dbus-daemon[642]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' Jun 28 20:13:26 volumio.local systemd[1]: Started RealtimeKit Scheduling Policy Service. Jun 28 20:13:26 volumio.local rtkit-daemon[1750]: Successfully called chroot. Jun 28 20:13:26 volumio.local rtkit-daemon[1750]: Successfully dropped privileges. Jun 28 20:13:26 volumio.local rtkit-daemon[1750]: Successfully limited resources. Jun 28 20:13:26 volumio.local rtkit-daemon[1750]: Running. Jun 28 20:13:26 volumio.local rtkit-daemon[1750]: Canary thread running. Jun 28 20:13:26 volumio.local dbus-daemon[642]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.23' (uid=0 pid=1750 comm="/usr/lib/rtkit/rtkit-daemon ") Jun 28 20:13:26 volumio.local rtkit-daemon[1750]: Watchdog thread running. Jun 28 20:13:26 volumio.local systemd[1]: Starting Authorization Manager... Jun 28 20:13:26 volumio.local volumio[1149]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 28 20:13:26 volumio.local polkitd[1754]: started daemon version 0.105 using authority implementation `local' version `0.105' Jun 28 20:13:26 volumio.local dbus-daemon[642]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Jun 28 20:13:26 volumio.local systemd[1]: Started Authorization Manager. Jun 28 20:13:26 volumio.local pulseaudio[1749]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Jun 28 20:13:26 volumio.local pulseaudio[1749]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Jun 28 20:13:26 volumio.local bluetoothd[754]: Endpoint registered: sender=:1.43 path=/MediaEndpoint/A2DPSource Jun 28 20:13:26 volumio.local bluetoothd[754]: Endpoint registered: sender=:1.43 path=/MediaEndpoint/A2DPSink Jun 28 20:13:26 volumio.local volumiobt[1739]: Applying permissions Jun 28 20:13:26 volumio.local volumiobt[1739]: Setting BT discoverable and pairable Jun 28 20:13:26 volumio.local pulseaudio[1749]: Failed to register as a handsfree audio agent with ofono: org.freedesktop.DBus.Error.ServiceUnknown: The name org.ofono was not provided by any .service files Jun 28 20:13:26 volumio.local kernel: Bluetooth: RFCOMM TTY layer initialized Jun 28 20:13:26 volumio.local kernel: Bluetooth: RFCOMM socket layer initialized Jun 28 20:13:26 volumio.local kernel: Bluetooth: RFCOMM ver 1.11 Jun 28 20:13:26 volumio.local volumiobt[1739]: Agent registered Jun 28 20:13:26 volumio.local volumiobt[1739]: [bluetooth]# -e power on Jun 28 20:13:26 volumio.local volumiobt[1739]: Invalid command in menu main: -e Jun 28 20:13:26 volumio.local volumiobt[1739]: Jun 28 20:13:26 volumio.local volumiobt[1739]: Use "help" for a list of available commands in a menu. Jun 28 20:13:26 volumio.local volumiobt[1739]: Use "menu " if you want to enter any submenu. Jun 28 20:13:26 volumio.local volumiobt[1739]: Use "back" if you want to return to menu main. Jun 28 20:13:26 volumio.local volumiobt[1739]: [bluetooth]# agent on Jun 28 20:13:26 volumio.local volumiobt[1739]: Agent is already registered Jun 28 20:13:26 volumio.local volumiobt[1739]: [bluetooth]# discoverable on Jun 28 20:13:26 volumio.local volumiobt[1739]: [bluetooth]# pairable on Jun 28 20:13:26 volumio.local volumiobt[1739]: [bluetooth]# agent NoInputNoOutput Jun 28 20:13:26 volumio.local volumiobt[1739]: Agent is already registered Jun 28 20:13:26 volumio.local volumiobt[1739]: [bluetooth]# default-agent Jun 28 20:13:26 volumio.local volumiobt[1739]: [bluetooth]# quit Jun 28 20:13:26 volumio.local volumiobt[1739]: [59B blob data] Jun 28 20:13:26 volumio.local volumio[1149]: info: MRS: Getting audio outputs on start Jun 28 20:13:26 volumio.local volumio[1149]: info: MRS: Requesting all other devices output Jun 28 20:13:29 volumio.local volumio[1149]: info: BOOT COMPLETED Jun 28 20:13:29 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 28 20:13:29 volumio.local volumio[1149]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jun 28 20:13:29 volumio.local volumio[1149]: info: CoreCommandRouter::volumioGetState Jun 28 20:13:32 volumio.local volumio[1149]: info: CoreCommandRouter::volumioStop Jun 28 20:13:32 volumio.local volumio[1149]: info: CoreStateMachine::stop Jun 28 20:13:32 volumio.local volumio[1149]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 28 20:13:32 volumio.local volumio[1149]: info: CoreStateMachine::stPlaybackTimer Jun 28 20:13:32 volumio.local volumio[1149]: info: CoreStateMachine::updateTrackBlock Jun 28 20:13:32 volumio.local volumio[1149]: info: CorePlayQueue::getTrackBlock Jun 28 20:13:32 volumio.local volumio[1149]: info: CoreStateMachine::pushState Jun 28 20:13:32 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:32 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 28 20:13:32 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPushState Jun 28 20:13:32 volumio.local volumio[1149]: info: MRS: Pushing multiroomSync output update for this device Jun 28 20:13:32 volumio.local volumio[1149]: info: MRS: Pushing multiroomSync output Jun 28 20:13:32 volumio.local volumio[1149]: info: CoreStateMachine::serviceStop Jun 28 20:13:32 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:32 volumio.local volumio[1149]: info: CoreCommandRouter::serviceStop Jun 28 20:13:32 volumio.local volumio[1149]: info: [1751134412010] ControllerWebradio::stop Jun 28 20:13:32 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand stop Jun 28 20:13:32 volumio.local volumio[1149]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Jun 28 20:13:32 volumio.local volumio[1149]: info: sendMpdCommand stop took 23 milliseconds Jun 28 20:13:32 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPlay Jun 28 20:13:32 volumio.local volumio[1149]: info: CoreStateMachine::play index undefined Jun 28 20:13:32 volumio.local volumio[1149]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 28 20:13:32 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:32 volumio.local volumio[1149]: info: CoreStateMachine::startPlaybackTimer Jun 28 20:13:32 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:32 volumio.local volumio[1149]: info: CoreCommandRouter::volumioGetVisibleSources Jun 28 20:13:32 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 28 20:13:32 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jun 28 20:13:32 volumio.local volumio[1149]: info: [1751134412824] ControllerWebradio::clearAddPlayTrack Jun 28 20:13:32 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand stop Jun 28 20:13:32 volumio.local volumio[1149]: info: sendMpdCommand stop took 0 milliseconds Jun 28 20:13:32 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand clear Jun 28 20:13:32 volumio.local volumio[1149]: info: Jun 28 20:13:32 volumio.local volumio[1149]: ---------------------------- MPD announces system playlist update Jun 28 20:13:32 volumio.local volumio[1149]: info: Ignoring MPD Status Update Jun 28 20:13:32 volumio.local volumio[1149]: info: sendMpdCommand clear took 2 milliseconds Jun 28 20:13:32 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand load "https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3" Jun 28 20:13:32 volumio.local volumio[1149]: error: updateQueue error: null Jun 28 20:13:32 volumio.local volumio[1149]: info: ------------------------------ 4ms Jun 28 20:13:33 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 28 20:13:33 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:33 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 28 20:13:33 volumio.local volumio[1494]: ..........................................................................................................................................................................................................................++++ Jun 28 20:13:33 volumio.local volumio-remote-updater[644]: No test mode Jun 28 20:13:33 volumio.local volumio-remote-updater[644]: No alpha test mode Jun 28 20:13:33 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jun 28 20:13:33 volumio.local volumio[1149]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Jun 28 20:13:33 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jun 28 20:13:34 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:34 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:34 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jun 28 20:13:34 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jun 28 20:13:34 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jun 28 20:13:34 volumio.local volumio[1149]: info: CoreCommandRouter::volumioGetBrowseSources Jun 28 20:13:34 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 28 20:13:34 volumio.local go-librespot[1356]: time="2025-06-28T20:13:34+02:00" level=trace msg="sent dealer ping" Jun 28 20:13:34 volumio.local go-librespot[1356]: time="2025-06-28T20:13:34+02:00" level=trace msg="received dealer pong" Jun 28 20:13:34 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand add "https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3" Jun 28 20:13:34 volumio.local volumio[1149]: info: Jun 28 20:13:34 volumio.local volumio[1149]: ---------------------------- MPD announces system playlist update Jun 28 20:13:34 volumio.local volumio[1149]: info: Ignoring MPD Status Update Jun 28 20:13:34 volumio.local volumio[1149]: info: sendMpdCommand add "https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3" took 1 milliseconds Jun 28 20:13:34 volumio.local volumio[1149]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 28 20:13:34 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand play Jun 28 20:13:34 volumio.local volumio[1149]: info: ------------------------------ 2ms Jun 28 20:13:34 volumio.local volumio[1149]: info: sendMpdCommand play took 4 milliseconds Jun 28 20:13:35 volumio.local volumio[1149]: info: Jun 28 20:13:35 volumio.local volumio[1149]: ---------------------------- MPD announces state update: player Jun 28 20:13:35 volumio.local volumio[1149]: info: ControllerMpd::getState Jun 28 20:13:35 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand status Jun 28 20:13:35 volumio.local volumio[1149]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jun 28 20:13:35 volumio.local volumio[1149]: info: FusionDsp - ---- read samplerate from file: 44100 Jun 28 20:13:35 volumio.local volumio[1149]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 28 20:13:35 volumio.local volumio[1149]: info: Jun 28 20:13:35 volumio.local volumio[1149]: ---------------------------- MPD announces system playlist update Jun 28 20:13:35 volumio.local volumio[1149]: info: Ignoring MPD Status Update Jun 28 20:13:35 volumio.local volumio[1149]: info: Jun 28 20:13:35 volumio.local volumio[1149]: ---------------------------- MPD announces state update: player Jun 28 20:13:35 volumio.local volumio[1149]: info: sendMpdCommand status took 32 milliseconds Jun 28 20:13:35 volumio.local volumio[1149]: info: ControllerMpd::getState Jun 28 20:13:35 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand status Jun 28 20:13:35 volumio.local volumio[1149]: verbose: ControllerMpd::parseState Jun 28 20:13:35 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 28 20:13:35 volumio.local volumio[1149]: info: ------------------------------ 3ms Jun 28 20:13:35 volumio.local volumio[1149]: info: sendMpdCommand status took 2 milliseconds Jun 28 20:13:35 volumio.local volumio[1149]: info: sendMpdCommand playlistinfo took 2 milliseconds Jun 28 20:13:35 volumio.local volumio[1149]: verbose: ControllerMpd::parseState Jun 28 20:13:35 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 28 20:13:35 volumio.local volumio[1149]: verbose: ControllerMpd::parseTrackInfo Jun 28 20:13:35 volumio.local volumio[1149]: info: ControllerMpd::pushState Jun 28 20:13:35 volumio.local volumio[1149]: info: CoreCommandRouter::servicePushState Jun 28 20:13:35 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:35 volumio.local volumio[1149]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"DAVID GUETTA FEAT. NE-YO & AKON - PLAY HARD","artist":"Absolut AI","album":null,"uri":"https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3","trackType":""} Jun 28 20:13:35 volumio.local volumio[1149]: verbose: CURRENT POSITION 0 Jun 28 20:13:35 volumio.local volumio[1149]: info: CoreStateMachine::syncState stateService play Jun 28 20:13:35 volumio.local volumio[1149]: info: CoreStateMachine::syncState currentStatus stop Jun 28 20:13:35 volumio.local volumio[1149]: info: ------------------------------ 38ms Jun 28 20:13:35 volumio.local volumio[1149]: info: sendMpdCommand playlistinfo took 12 milliseconds Jun 28 20:13:35 volumio.local volumio[1149]: verbose: ControllerMpd::parseTrackInfo Jun 28 20:13:35 volumio.local volumio[1149]: info: ControllerMpd::pushState Jun 28 20:13:35 volumio.local volumio[1149]: info: CoreCommandRouter::servicePushState Jun 28 20:13:35 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:35 volumio.local volumio[1149]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1229,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"DAVID GUETTA FEAT. NE-YO & AKON - PLAY HARD","artist":"Absolut AI","album":null,"uri":"https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3","trackType":""} Jun 28 20:13:35 volumio.local volumio[1149]: verbose: CURRENT POSITION 0 Jun 28 20:13:35 volumio.local volumio[1149]: info: CoreStateMachine::syncState stateService play Jun 28 20:13:35 volumio.local volumio[1149]: info: CoreStateMachine::syncState currentStatus play Jun 28 20:13:35 volumio.local volumio[1149]: info: Received an update from plugin. extracting info from payload Jun 28 20:13:35 volumio.local volumio[1149]: info: CoreStateMachine::pushState Jun 28 20:13:35 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 28 20:13:35 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPushState Jun 28 20:13:35 volumio.local volumio[1149]: info: MRS: Pushing multiroomSync output update for this device Jun 28 20:13:35 volumio.local volumio[1149]: info: MRS: Pushing multiroomSync output Jun 28 20:13:35 volumio.local volumio[1149]: info: CoreStateMachine::pushState Jun 28 20:13:35 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPushState Jun 28 20:13:35 volumio.local volumio[1149]: info: MRS: Pushing multiroomSync output update for this device Jun 28 20:13:35 volumio.local volumio[1149]: info: MRS: Pushing multiroomSync output Jun 28 20:13:35 volumio.local volumio[1149]: info: ------------------------------ 46ms Jun 28 20:13:35 volumio.local volumio[1149]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Jun 28 20:13:35 volumio.local volumio[1149]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Jun 28 20:13:35 volumio.local volumio[1149]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 28 20:13:36 volumio.local volumio[1149]: info: Jun 28 20:13:36 volumio.local volumio[1149]: ---------------------------- MPD announces system playlist update Jun 28 20:13:36 volumio.local volumio[1149]: info: Ignoring MPD Status Update Jun 28 20:13:36 volumio.local volumio[1149]: info: Jun 28 20:13:36 volumio.local volumio[1149]: ---------------------------- MPD announces state update: player Jun 28 20:13:36 volumio.local volumio[1149]: info: ControllerMpd::getState Jun 28 20:13:36 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand status Jun 28 20:13:36 volumio.local volumio[1149]: info: ------------------------------ 3ms Jun 28 20:13:36 volumio.local volumio[1149]: info: sendMpdCommand status took 2 milliseconds Jun 28 20:13:36 volumio.local volumio[1149]: verbose: ControllerMpd::parseState Jun 28 20:13:36 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 28 20:13:36 volumio.local volumio[1149]: info: sendMpdCommand playlistinfo took 1 milliseconds Jun 28 20:13:36 volumio.local volumio[1149]: verbose: ControllerMpd::parseTrackInfo Jun 28 20:13:36 volumio.local volumio[1149]: info: ControllerMpd::pushState Jun 28 20:13:36 volumio.local volumio[1149]: info: CoreCommandRouter::servicePushState Jun 28 20:13:36 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:36 volumio.local volumio[1149]: verbose: STATE SERVICE {"status":"play","position":0,"seek":3480,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"DAVID GUETTA FEAT. NE-YO & AKON - PLAY HARD","artist":"Absolut AI","album":null,"uri":"https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3","trackType":""} Jun 28 20:13:36 volumio.local volumio[1149]: verbose: CURRENT POSITION 0 Jun 28 20:13:36 volumio.local volumio[1149]: info: CoreStateMachine::syncState stateService play Jun 28 20:13:36 volumio.local volumio[1149]: info: CoreStateMachine::syncState currentStatus play Jun 28 20:13:36 volumio.local volumio[1149]: info: Received an update from plugin. extracting info from payload Jun 28 20:13:36 volumio.local volumio[1149]: info: CoreStateMachine::pushState Jun 28 20:13:36 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 28 20:13:36 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPushState Jun 28 20:13:36 volumio.local volumio[1149]: info: MRS: Pushing multiroomSync output update for this device Jun 28 20:13:36 volumio.local volumio[1149]: info: MRS: Pushing multiroomSync output Jun 28 20:13:36 volumio.local volumio[1149]: info: CoreStateMachine::pushState Jun 28 20:13:36 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPushState Jun 28 20:13:36 volumio.local volumio[1149]: info: MRS: Pushing multiroomSync output update for this device Jun 28 20:13:36 volumio.local volumio[1149]: info: MRS: Pushing multiroomSync output Jun 28 20:13:36 volumio.local volumio[1149]: info: ------------------------------ 49ms Jun 28 20:13:36 volumio.local volumio[1149]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Jun 28 20:13:36 volumio.local volumio[1149]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Jun 28 20:13:38 volumio.local volumio[1494]: .............................................................++++ Jun 28 20:13:38 volumio.local volumio[1494]: e is 65537 (0x010001) Jun 28 20:13:38 volumio.local volumio[1494]: writing RSA key Jun 28 20:13:43 volumio.local ntpd[773]: Soliciting pool server 217.91.44.17 Jun 28 20:13:43 volumio.local ntpd[773]: Soliciting pool server 185.41.106.152 Jun 28 20:13:43 volumio.local volumio[1149]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 28 20:13:43 volumio.local volumio[1149]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 28 20:13:43 volumio.local volumio[1149]: info: Retrieving Cloud Streaming UI Jun 28 20:13:43 volumio.local volumio[1149]: info: Getting Tidal Cloud Configuration Jun 28 20:13:43 volumio.local volumio[1149]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 28 20:13:43 volumio.local volumio[1149]: info: Getting Qobuz Cloud Configuration Jun 28 20:13:43 volumio.local volumio[1149]: info: Asking plugin for UI Config Jun 28 20:13:43 volumio.local volumio[1149]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 28 20:13:43 volumio.local volumio[1149]: info: Getting Spotify Cloud Configuration Jun 28 20:13:43 volumio.local volumio[1149]: info: Asking plugin for UI Config Jun 28 20:13:43 volumio.local volumio[1149]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 28 20:13:43 volumio.local volumio[1149]: info: Saving Spotify Acccount Jun 28 20:13:43 volumio.local volumio[1149]: info: Got it Jun 28 20:13:43 volumio.local volumio[1149]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Jun 28 20:13:43 volumio.local volumio[1149]: info: Got it Jun 28 20:13:43 volumio.local volumio[1149]: info: Got Tidal Cloud Configuration Jun 28 20:13:43 volumio.local volumio[1149]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 28 20:13:43 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jun 28 20:13:43 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 28 20:13:43 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 28 20:13:43 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 28 20:13:43 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 28 20:13:43 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 28 20:13:43 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 28 20:13:43 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 28 20:13:43 volumio.local volumio[1149]: info: CoreCommandRouter::volumioGetBrowseSources Jun 28 20:13:43 volumio.local volumio[1149]: info: CoreCommandRouter::volumioGetBrowseSources Jun 28 20:13:43 volumio.local volumio[1149]: info: CoreCommandRouter::volumioGetBrowseSources Jun 28 20:13:43 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 28 20:13:43 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jun 28 20:13:44 volumio.local ntpd[773]: Soliciting pool server 217.79.189.239 Jun 28 20:13:44 volumio.local ntpd[773]: Soliciting pool server 178.63.52.50 Jun 28 20:13:44 volumio.local ntpd[773]: Soliciting pool server 178.215.228.24 Jun 28 20:13:45 volumio.local ntpd[773]: Soliciting pool server 144.91.126.59 Jun 28 20:13:45 volumio.local ntpd[773]: Soliciting pool server 144.76.76.107 Jun 28 20:13:45 volumio.local ntpd[773]: Soliciting pool server 136.243.7.20 Jun 28 20:13:45 volumio.local ntpd[773]: Soliciting pool server 49.13.223.236 Jun 28 20:13:46 volumio.local ntpd[773]: Soliciting pool server 49.13.14.46 Jun 28 20:13:46 volumio.local ntpd[773]: Soliciting pool server 141.98.136.83 Jun 28 20:13:46 volumio.local ntpd[773]: Soliciting pool server 85.220.190.246 Jun 28 20:13:46 volumio.local ntpd[773]: Soliciting pool server 185.252.140.125 Jun 28 20:13:47 volumio.local ntpd[773]: Soliciting pool server 94.130.23.46 Jun 28 20:13:47 volumio.local ntpd[773]: Soliciting pool server 51.75.67.47 Jun 28 20:13:47 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 28 20:13:48 volumio.local ntpd[773]: Soliciting pool server 78.47.93.191 Jun 28 20:13:48 volumio.local ntpd[773]: Soliciting pool server 2003:a:47f:abe4::2 Jun 28 20:13:50 volumio.local volumio[1149]: info: Jun 28 20:13:50 volumio.local volumio[1149]: ---------------------------- MPD announces system playlist update Jun 28 20:13:50 volumio.local volumio[1149]: info: Ignoring MPD Status Update Jun 28 20:13:50 volumio.local volumio[1149]: info: Jun 28 20:13:50 volumio.local volumio[1149]: ---------------------------- MPD announces state update: player Jun 28 20:13:50 volumio.local volumio[1149]: info: ControllerMpd::getState Jun 28 20:13:50 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand status Jun 28 20:13:50 volumio.local volumio[1149]: info: ------------------------------ 3ms Jun 28 20:13:50 volumio.local volumio[1149]: info: sendMpdCommand status took 2 milliseconds Jun 28 20:13:50 volumio.local volumio[1149]: verbose: ControllerMpd::parseState Jun 28 20:13:50 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 28 20:13:50 volumio.local volumio[1149]: info: sendMpdCommand playlistinfo took 1 milliseconds Jun 28 20:13:50 volumio.local volumio[1149]: verbose: ControllerMpd::parseTrackInfo Jun 28 20:13:50 volumio.local volumio[1149]: info: ControllerMpd::pushState Jun 28 20:13:50 volumio.local volumio[1149]: info: CoreCommandRouter::servicePushState Jun 28 20:13:50 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:13:50 volumio.local volumio[1149]: verbose: STATE SERVICE {"status":"play","position":0,"seek":17980,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Absolut Radio AI - der erste Stream von künstlicher Intelligenz","artist":"Absolut AI","album":null,"uri":"https://absolut-ai.live-sm.absolutradio.de/absolut-ai/stream/mp3","trackType":""} Jun 28 20:13:50 volumio.local volumio[1149]: verbose: CURRENT POSITION 0 Jun 28 20:13:50 volumio.local volumio[1149]: info: CoreStateMachine::syncState stateService play Jun 28 20:13:50 volumio.local volumio[1149]: info: CoreStateMachine::syncState currentStatus play Jun 28 20:13:50 volumio.local volumio[1149]: info: Received an update from plugin. extracting info from payload Jun 28 20:13:50 volumio.local volumio[1149]: info: CoreStateMachine::pushState Jun 28 20:13:50 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 28 20:13:50 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPushState Jun 28 20:13:50 volumio.local volumio[1149]: info: MRS: Pushing multiroomSync output update for this device Jun 28 20:13:50 volumio.local volumio[1149]: info: MRS: Pushing multiroomSync output Jun 28 20:13:50 volumio.local volumio[1149]: info: CoreStateMachine::pushState Jun 28 20:13:50 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPushState Jun 28 20:13:50 volumio.local volumio[1149]: info: MRS: Pushing multiroomSync output update for this device Jun 28 20:13:50 volumio.local volumio[1149]: info: MRS: Pushing multiroomSync output Jun 28 20:13:50 volumio.local volumio[1149]: info: ------------------------------ 36ms Jun 28 20:13:50 volumio.local volumio[1149]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Jun 28 20:13:50 volumio.local volumio[1149]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Jun 28 20:13:51 volumio.local ntpd[773]: receive: Unexpected origin timestamp 0xec0aaf5f.3262c028 does not match aorg 0000000000.00000000 from server@185.41.106.152 xmt 0xec0aaf5f.a25a3fcc Jun 28 20:13:51 volumio.local ntpd[773]: receive: Unexpected origin timestamp 0xec0aaf5f.3261e0d7 does not match aorg 0000000000.00000000 from server@217.91.44.17 xmt 0xec0aaf5f.a30fce34 Jun 28 20:13:52 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 28 20:13:53 volumio.local volumio[1149]: info: Disabling MyMusic plugin multiroom Jun 28 20:13:53 volumio.local volumio[1149]: info: [MyVolumio PluginManager] Disabling and stopping plugin audio_interface multiroom Jun 28 20:13:53 volumio.local volumio[1149]: info: Disabling plugin multiroom Jun 28 20:13:53 volumio.local volumio[1149]: info: Preparing to generate the ALSA configuration file Jun 28 20:13:53 volumio.local volumio[1149]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jun 28 20:13:53 volumio.local volumio[1149]: info: Reading ALSA contributions from plugins. Jun 28 20:13:53 volumio.local volumio[1149]: info: Asound.conf file written Jun 28 20:13:53 volumio.local sudo[1951]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Jun 28 20:13:53 volumio.local sudo[1951]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:53 volumio.local sudo[1951]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:53 volumio.local volumio[1149]: xcb_connection_has_error() returned true Jun 28 20:13:53 volumio.local volumio[1149]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:Max Overclock PLL:0' : Device or resource busy Jun 28 20:13:53 volumio.local volumio[1149]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:Max Overclock DSP:0' : Device or resource busy Jun 28 20:13:53 volumio.local volumio[1149]: /usr/sbin/alsactl: set_control:1461: Cannot write control '2:0:0:Max Overclock DAC:0' : Device or resource busy Jun 28 20:13:53 volumio.local volumio[1149]: info: Output device has changed, restarting MPD Jun 28 20:13:53 volumio.local sudo[1956]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 28 20:13:53 volumio.local sudo[1956]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:53 volumio.local volumio[1149]: info: Output device has changed, restarting Shairport Sync Jun 28 20:13:53 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:53 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:53 volumio.local sudo[1956]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:53 volumio.local sudo[1959]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 28 20:13:53 volumio.local sudo[1959]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:53 volumio.local systemd[1]: Stopping Music Player Daemon... Jun 28 20:13:53 volumio.local volumio[1149]: xcb_connection_has_error() returned true Jun 28 20:13:53 volumio.local volumio[1149]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 28 20:13:53 volumio.local volumio[1149]: xcb_connection_has_error() returned true Jun 28 20:13:53 volumio.local volumio[1149]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Jun 28 20:13:53 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:53 volumio.local systemd[1]: mpd.service: Succeeded. Jun 28 20:13:53 volumio.local systemd[1]: Stopped Music Player Daemon. Jun 28 20:13:53 volumio.local volumio[1149]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 28 20:13:53 volumio.local volumio[1149]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 28 20:13:53 volumio.local volumio[1149]: info: MPD Permissions set Jun 28 20:13:53 volumio.local volumio[1149]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read property 'split' of undefined Jun 28 20:13:53 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:53 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:53 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:53 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:53 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:53 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:53 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:53 volumio.local systemd[1]: Starting Music Player Daemon... Jun 28 20:13:53 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 20:13:53 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 20:13:53 volumio.local volumio[1149]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 28 20:13:53 volumio.local volumio[1149]: info: Starting Shairport Sync Jun 28 20:13:53 volumio.local sudo[1972]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 28 20:13:53 volumio.local sudo[1972]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:53 volumio.local sudo[1966]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 28 20:13:53 volumio.local sudo[1966]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 20:13:53 volumio.local sudo[1966]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:53 volumio.local systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 28 20:13:53 volumio.local systemd[1]: shairport-sync.service: Succeeded. Jun 28 20:13:53 volumio.local systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 28 20:13:53 volumio.local volumio[1149]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 28 20:13:53 volumio.local volumio[1149]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 28 20:13:53 volumio.local systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 28 20:13:53 volumio.local sudo[1972]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:53 volumio.local volumio[1149]: info: Shairport-Sync Started Jun 28 20:13:53 volumio.local volumio[1149]: error: Upnp client error: Error: This socket has been ended by the other party Jun 28 20:13:54 volumio.local mpd[1975]: Jun 28 20:13 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 28 20:13:54 volumio.local systemd[1]: Started Music Player Daemon. Jun 28 20:13:54 volumio.local sudo[1959]: pam_unix(sudo:session): session closed for user root Jun 28 20:13:54 volumio.local volumio[1149]: error: updateQueue error: null Jun 28 20:13:56 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 28 20:14:00 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 28 20:14:04 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 28 20:14:04 volumio.local go-librespot[1356]: time="2025-06-28T20:14:04+02:00" level=trace msg="sent dealer ping" Jun 28 20:14:04 volumio.local go-librespot[1356]: time="2025-06-28T20:14:04+02:00" level=trace msg="received dealer pong" Jun 28 20:14:08 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 28 20:14:08 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getHwuuid Jun 28 20:14:08 volumio.local volumio[1149]: info: Pausing Remote Device: http://192.168.50.222 Jun 28 20:14:08 volumio.local volumio[1149]: info: Jun 28 20:14:08 volumio.local volumio[1149]: ---------------------------- Client requests Volumio pause Jun 28 20:14:08 volumio.local volumio[1149]: info: CoreCommandRouter::volumioPause Jun 28 20:14:08 volumio.local volumio[1149]: info: CoreStateMachine::pause Jun 28 20:14:08 volumio.local volumio[1149]: info: CoreStateMachine::stPlaybackTimer Jun 28 20:14:08 volumio.local volumio[1149]: info: CoreStateMachine::servicePause Jun 28 20:14:08 volumio.local volumio[1149]: info: CorePlayQueue::getTrack 0 Jun 28 20:14:08 volumio.local volumio[1149]: info: CoreCommandRouter::servicePause Jun 28 20:14:08 volumio.local volumio[1149]: info: [1751134448423] ControllerWebradio::pause Jun 28 20:14:08 volumio.local volumio[1149]: verbose: ControllerMpd::sendMpdCommand pause Jun 28 20:14:08 volumio.local volumio[1149]: info: sendMpdCommand pause took 1 milliseconds Jun 28 20:14:08 volumio.local volumio[1149]: info: Done pausing: Jun 28 20:14:09 volumio.local volumio[1149]: info: CoreCommandRouter::executeOnPlugin: multiroom , audioOutputPause Jun 28 20:14:09 volumio.local volumio[1149]: info: Error : CoreCommandRouter::executeOnPlugin: No method [audioOutputPause] in plugin multiroom Jun 28 20:14:09 volumio.local volumio[1149]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 28 20:14:09 volumio.local volumio[1149]: TypeError: Cannot read property 'then' of undefined Jun 28 20:14:09 volumio.local volumio[1149]: at outputs.audioOutputPause (/volumio/app/plugins/audio_interface/outputs/index.js:417:9) Jun 28 20:14:09 volumio.local volumio[1149]: at CoreCommandRouter.audioOutputPause (/volumio/app/index.js:2290:30) Jun 28 20:14:09 volumio.local volumio[1149]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1462:26) Jun 28 20:14:09 volumio.local volumio[1149]: at Socket.emit (events.js:315:20) Jun 28 20:14:09 volumio.local volumio[1149]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Jun 28 20:14:09 volumio.local volumio[1149]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Jun 28 20:14:09 volumio.local volumio[1149]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 28 20:14:10 volumio.local sudo[2058]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-28 20:13 Jun 28 20:14:10 volumio.local sudo[2058]: 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="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 10 Jun 2025 04:52:53 PM CEST" VOLUMIO_VERSION="3.816" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="a72866a0de4045751d03a035de6290e1"