May 29 15:18:21 voluxivmio ntpd[908]: CLOCK: time stepped by 277.443903
May 29 15:18:21 voluxivmio ntpd[908]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes
May 29 15:18:22 voluxivmio volumio[1175]: info: Loading plugin "spop"...
May 29 15:18:22 voluxivmio systemd[1]: systemd-fsckd.service: Deactivated successfully.
May 29 15:18:23 voluxivmio dhcpcd[659]: timed out
May 29 15:18:23 voluxivmio sh[646]: timed out
May 29 15:18:23 voluxivmio dhcpcd[659]: dhcpcd exited
May 29 15:18:23 voluxivmio sh[593]: ifup: failed to bring up eth0
May 29 15:18:23 voluxivmio systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE
May 29 15:18:23 voluxivmio systemd[1]: ifup@eth0.service: Failed with result 'exit-code'.
May 29 15:18:23 voluxivmio sudo[1250]: pam_unix(sudo:session): session closed for user root
May 29 15:18:23 voluxivmio volumio[1175]: info: Loading plugin "youtube2"...
May 29 15:18:24 voluxivmio systemd[1]: systemd-hostnamed.service: Deactivated successfully.
May 29 15:18:25 voluxivmio volumio[1175]: info: Loading plugin "ytcr"...
May 29 15:18:26 voluxivmio volumio-remote-updater[714]: [2025-05-29 15:18:26] [connect] Successful connection
May 29 15:18:28 voluxivmio volumio[1175]: info: Loading plugin "ytmusic"...
May 29 15:18:30 voluxivmio volumio[1175]: info: Loading plugin "now_playing"...
May 29 15:18:31 voluxivmio volumio[1175]: info: Loading plugin "outputs"...
May 29 15:18:31 voluxivmio volumio[1175]: info: Loading plugin "albumart"...
May 29 15:18:31 voluxivmio volumio[1175]: info: Plugin example_plugin is not enabled
May 29 15:18:31 voluxivmio volumio[1175]: info: Loading plugin "inputs"...
May 29 15:18:31 voluxivmio volumio[1175]: info: Loading plugin "updater_comm"...
May 29 15:18:31 voluxivmio volumio[1175]: info: Plugin mpdemulation is not enabled
May 29 15:18:31 voluxivmio volumio[1175]: info: Loading plugin "rest_api"...
May 29 15:18:31 voluxivmio volumio[1175]: info: Loading plugin "websocket"...
May 29 15:18:31 voluxivmio volumio[1175]: info: Starting Socket.io Server version 1.7.4
May 29 15:18:31 voluxivmio volumio[1175]: info: Loading plugin "fusiondsp"...
May 29 15:18:32 voluxivmio volumio[1307]: Forking 3 albumart workers
May 29 15:18:32 voluxivmio volumio[1175]: info: Applying required configuration parameters for plugin fusiondsp
May 29 15:18:32 voluxivmio volumio[1175]: info: Loading plugin "mpdoutput"...
May 29 15:18:32 voluxivmio volumio[1175]: info: Loading plugin "motherearthradio"...
May 29 15:18:33 voluxivmio volumio[1175]: info: Applying required configuration parameters for plugin motherearthradio
May 29 15:18:33 voluxivmio volumio[1175]: info: [1748524713501] [MotherEarth] API delay: 5
May 29 15:18:33 voluxivmio volumio[1175]: info: Loading plugin "podcast"...
May 29 15:18:34 voluxivmio volumio[1175]: info: ControllerPodcast::constructor
May 29 15:18:34 voluxivmio volumio[1175]: info: Loading i18n strings for locale fr
May 29 15:18:34 voluxivmio volumio[1175]: info: Plugin mpdoutput has duplicated i18n key SAVE. It is ignored.
May 29 15:18:34 voluxivmio volumio[1175]: Updating browse sources language
May 29 15:18:34 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 29 15:18:34 voluxivmio volumio[1317]: Starting albumart workers
May 29 15:18:35 voluxivmio volumio[1318]: Starting albumart workers
May 29 15:18:35 voluxivmio volumio[1319]: Starting albumart workers
May 29 15:18:35 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
May 29 15:18:35 voluxivmio volumio[1175]: info: CoreCommandRouter::initPlayerControls
May 29 15:18:35 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:35 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:35 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:35 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:35 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:35 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:35 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:35 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:35 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
May 29 15:18:35 voluxivmio volumio[1175]: Express server listening on port 3000
May 29 15:18:35 voluxivmio volumio[1175]: [Metrics] WebUI: 18s 445.82ms
May 29 15:18:35 voluxivmio volumio[1175]: info: CoreStateMachine::resetVolumioState
May 29 15:18:35 voluxivmio volumio[1175]: info: CoreStateMachine::getcurrentVolume
May 29 15:18:35 voluxivmio volumio[1175]: info: CoreCommandRouter::volumioRetrievevolume
May 29 15:18:35 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 29 15:18:35 voluxivmio sudo[1352]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
May 29 15:18:35 voluxivmio sudo[1352]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 15:18:35 voluxivmio sudo[1354]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
May 29 15:18:35 voluxivmio sudo[1352]: pam_unix(sudo:session): session closed for user root
May 29 15:18:35 voluxivmio sudo[1354]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 15:18:35 voluxivmio sudo[1354]: pam_unix(sudo:session): session closed for user root
May 29 15:18:35 voluxivmio volumio[1175]: info: Volumio Network Manager: Network status updated: 2
May 29 15:18:36 voluxivmio volumio[1175]: info: VolumeController:: Volume=25 Mute =false
May 29 15:18:36 voluxivmio volumio[1175]: info: CoreStateMachine::pushState
May 29 15:18:36 voluxivmio volumio[1175]: info: CorePlayQueue::getTrack 0
May 29 15:18:36 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
May 29 15:18:36 voluxivmio volumio[1175]: info: CoreCommandRouter::volumioPushState
May 29 15:18:36 voluxivmio volumio[1175]: info: CoreStateMachine::updateTrackBlock
May 29 15:18:36 voluxivmio volumio[1175]: info: CorePlayQueue::getTrackBlock
May 29 15:18:36 voluxivmio volumio[1175]: info: CoreCommandRouter::volumioRetrievevolume
May 29 15:18:36 voluxivmio volumio[1175]: info: Reloading queue from file
May 29 15:18:36 voluxivmio volumio[1175]: info: CoreStateMachine::setRepeat null single undefined
May 29 15:18:36 voluxivmio volumio[1175]: info: CoreStateMachine::pushState
May 29 15:18:36 voluxivmio volumio[1175]: info: CorePlayQueue::getTrack 0
May 29 15:18:36 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
May 29 15:18:36 voluxivmio volumio[1175]: info: CoreCommandRouter::volumioPushState
May 29 15:18:36 voluxivmio volumio[1175]: info: CoreStateMachine::setRandom null
May 29 15:18:36 voluxivmio volumio[1175]: info: CoreStateMachine::pushState
May 29 15:18:36 voluxivmio volumio[1175]: info: CorePlayQueue::getTrack 0
May 29 15:18:36 voluxivmio volumio[1175]: info: CoreCommandRouter::volumioPushState
May 29 15:18:36 voluxivmio volumio[1175]: info: Setting Device type: Raspberry PI
May 29 15:18:36 voluxivmio volumio[1175]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb
May 29 15:18:36 voluxivmio volumio[1175]: info: USB Boot Capable - System SBC Revision found in cpuinfo: d03114
May 29 15:18:36 voluxivmio volumio[1175]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI
May 29 15:18:36 voluxivmio volumio[1175]: info: VolumeController:: Volume=25 Mute =false
May 29 15:18:36 voluxivmio volumio[1175]: info: CoreStateMachine::pushState
May 29 15:18:36 voluxivmio volumio[1175]: info: CorePlayQueue::getTrack 0
May 29 15:18:36 voluxivmio volumio[1175]: info: CoreCommandRouter::volumioPushState
May 29 15:18:36 voluxivmio volumio[1175]: info: Completed loading Core Plugins
May 29 15:18:36 voluxivmio volumio[1175]: info: Preparing to generate the ALSA configuration file
May 29 15:18:36 voluxivmio sudo[1376]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
May 29 15:18:36 voluxivmio sudo[1376]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 15:18:36 voluxivmio volumio[1175]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf
May 29 15:18:36 voluxivmio volumio[1175]: info: Reading ALSA contributions from plugins.
May 29 15:18:36 voluxivmio volumio[1175]: info: Asound.conf file written
May 29 15:18:36 voluxivmio sudo[1383]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf
May 29 15:18:36 voluxivmio sudo[1383]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 15:18:36 voluxivmio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
May 29 15:18:36 voluxivmio sudo[1376]: pam_unix(sudo:session): session closed for user root
May 29 15:18:36 voluxivmio sudo[1383]: pam_unix(sudo:session): session closed for user root
May 29 15:18:36 voluxivmio volumio[1175]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2
May 29 15:18:36 voluxivmio volumio[1175]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2
May 29 15:18:36 voluxivmio volumio[1175]: info: Output device has changed, restarting MPD
May 29 15:18:36 voluxivmio volumio[1175]: info: Output device has changed, restarting Shairport Sync
May 29 15:18:36 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:36 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 29 15:18:36 voluxivmio sudo[1406]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
May 29 15:18:36 voluxivmio sudo[1406]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 15:18:36 voluxivmio sudo[1406]: pam_unix(sudo:session): session closed for user root
May 29 15:18:36 voluxivmio sudo[1412]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
May 29 15:18:36 voluxivmio volumio[1175]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
May 29 15:18:36 voluxivmio volumio[1175]: info: ___________ START PLUGINS ___________
May 29 15:18:36 voluxivmio sudo[1412]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 15:18:36 voluxivmio volumio[1175]: info: ControllerMpd::onStart: Initializing MPD
May 29 15:18:36 voluxivmio volumio[1175]: info: Creating MPD Configuration file
May 29 15:18:36 voluxivmio sudo[1420]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
May 29 15:18:36 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
May 29 15:18:36 voluxivmio volumio[1175]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
May 29 15:18:36 voluxivmio volumio[1175]: info: [1748524716897] CoreMusicLibrary::Adding element Serveurs Média
May 29 15:18:36 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 29 15:18:36 voluxivmio sudo[1420]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 15:18:36 voluxivmio sudo[1420]: pam_unix(sudo:session): session closed for user root
May 29 15:18:36 voluxivmio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
May 29 15:18:36 voluxivmio systemd[1]: Starting mpd.service - Music Player Daemon...
May 29 15:18:36 voluxivmio sudo[1423]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
May 29 15:18:36 voluxivmio sudo[1423]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 15:18:37 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:37 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 29 15:18:37 voluxivmio sudo[1425]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
May 29 15:18:37 voluxivmio sudo[1425]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
May 29 15:18:37 voluxivmio sudo[1431]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory
May 29 15:18:37 voluxivmio sudo[1425]: pam_unix(sudo:session): session closed for user root
May 29 15:18:37 voluxivmio systemd[1]: mpd.service: Deactivated successfully.
May 29 15:18:37 voluxivmio systemd[1]: Stopped mpd.service - Music Player Daemon.
May 29 15:18:37 voluxivmio systemd[1]: mpd.socket: Deactivated successfully.
May 29 15:18:37 voluxivmio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
May 29 15:18:37 voluxivmio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
May 29 15:18:37 voluxivmio volumio[1175]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
May 29 15:18:37 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:37 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 29 15:18:37 voluxivmio volumio[1175]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
May 29 15:18:37 voluxivmio volumio[1175]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
May 29 15:18:37 voluxivmio volumio[1175]: info: [1748524717143] CoreMusicLibrary::Adding element Last_100
May 29 15:18:37 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 29 15:18:37 voluxivmio volumio[1175]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
May 29 15:18:37 voluxivmio volumio[1175]: info: [1748524717145] CoreMusicLibrary::Adding element Webradio
May 29 15:18:37 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 29 15:18:37 voluxivmio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
May 29 15:18:37 voluxivmio systemd[1]: Starting mpd.service - Music Player Daemon...
May 29 15:18:37 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
May 29 15:18:37 voluxivmio volumio[1175]: info: Initializing BBC Radios
May 29 15:18:37 voluxivmio sudo[1437]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
May 29 15:18:37 voluxivmio sudo[1437]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
May 29 15:18:37 voluxivmio sudo[1446]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory
May 29 15:18:37 voluxivmio sudo[1437]: pam_unix(sudo:session): session closed for user root
May 29 15:18:37 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
May 29 15:18:37 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 29 15:18:37 voluxivmio volumio[1175]: info: Adding Calm Radio to Browse Sources
May 29 15:18:37 voluxivmio volumio[1175]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
May 29 15:18:37 voluxivmio volumio[1175]: info: [1748524717332] CoreMusicLibrary::Adding element Calm Radio
May 29 15:18:37 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 29 15:18:37 voluxivmio volumio[1175]: Cannot find translation for source Calm Radio
May 29 15:18:37 voluxivmio volumio[1175]: info: Creating Spotify config file
May 29 15:18:37 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:37 voluxivmio volumio[1175]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
May 29 15:18:37 voluxivmio volumio[1175]: info: [1748524717408] CoreMusicLibrary::Adding element YouTube2
May 29 15:18:37 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 29 15:18:37 voluxivmio volumio[1175]: Cannot find translation for source Calm Radio
May 29 15:18:37 voluxivmio volumio[1175]: Cannot find translation for source YouTube2
May 29 15:18:37 voluxivmio volumio[1175]: info: [ytcr] Data store TTL expired - clearing it...
May 29 15:18:37 voluxivmio volumio[1175]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
May 29 15:18:37 voluxivmio volumio[1175]: info: [1748524717566] CoreMusicLibrary::Adding element YouTube Music
May 29 15:18:37 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 29 15:18:37 voluxivmio volumio[1175]: Cannot find translation for source Calm Radio
May 29 15:18:37 voluxivmio volumio[1175]: Cannot find translation for source YouTube2
May 29 15:18:37 voluxivmio volumio[1175]: Cannot find translation for source YouTube Music
May 29 15:18:37 voluxivmio volumio[1175]: info: [now-playing] ConfigUpdater: config is up to date.
May 29 15:18:37 voluxivmio volumio[1175]: info: Loading i18n strings for locale fr
May 29 15:18:37 voluxivmio volumio[1175]: info: Plugin mpdoutput has duplicated i18n key SAVE. It is ignored.
May 29 15:18:37 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile
May 29 15:18:37 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:37 voluxivmio volumio[1175]: info: FusionDsp - mixtype--------------------- Hardware
May 29 15:18:37 voluxivmio volumio[1175]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
May 29 15:18:37 voluxivmio volumio[1175]: info: [1748524717702] CoreMusicLibrary::Adding element Mother Earth Radio
May 29 15:18:37 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 29 15:18:37 voluxivmio volumio[1175]: Cannot find translation for source Calm Radio
May 29 15:18:37 voluxivmio volumio[1175]: Cannot find translation for source YouTube2
May 29 15:18:37 voluxivmio volumio[1175]: Cannot find translation for source YouTube Music
May 29 15:18:37 voluxivmio volumio[1175]: Cannot find translation for source Mother Earth Radio
May 29 15:18:37 voluxivmio volumio[1175]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
May 29 15:18:37 voluxivmio volumio[1175]: info: [1748524717727] CoreMusicLibrary::Adding element Podcast
May 29 15:18:37 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 29 15:18:37 voluxivmio volumio[1175]: Cannot find translation for source Calm Radio
May 29 15:18:37 voluxivmio volumio[1175]: Cannot find translation for source YouTube2
May 29 15:18:37 voluxivmio volumio[1175]: Cannot find translation for source YouTube Music
May 29 15:18:37 voluxivmio volumio[1175]: Cannot find translation for source Mother Earth Radio
May 29 15:18:37 voluxivmio volumio[1175]: Cannot find translation for source Podcast
May 29 15:18:37 voluxivmio volumio[1175]: info: Volumio Calling Home
May 29 15:18:37 voluxivmio systemd[1]: systemd-timedated.service: Deactivated successfully.
May 29 15:18:37 voluxivmio volumio[1175]: info: Log in to Calm Radio
May 29 15:18:37 voluxivmio volumio[1175]: info: Preparing to generate the ALSA configuration file
May 29 15:18:38 voluxivmio volumio[1175]: info: [now-playing] App is listening on port 4004.
May 29 15:18:38 voluxivmio volumio[1175]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds
May 29 15:18:39 voluxivmio volumio[1175]: info: Discovery: adding afa39815-6046-4c64-97f4-fca13a6dcdcb
May 29 15:18:39 voluxivmio volumio[1175]: info: Discovery: Found device Voluxivmio
May 29 15:18:39 voluxivmio volumio[1175]: info: CoreCommandRouter::volumioGetState
May 29 15:18:39 voluxivmio volumio[1175]: info: CorePlayQueue::getTrack 0
May 29 15:18:39 voluxivmio volumio[1175]: info: Discovery: this is already registered, afa39815-6046-4c64-97f4-fca13a6dcdcb
May 29 15:18:39 voluxivmio volumio[1175]: info: Discovery: Found device Voluxivmio
May 29 15:18:39 voluxivmio volumio[1175]: info: CoreCommandRouter::volumioGetState
May 29 15:18:39 voluxivmio volumio[1175]: info: CorePlayQueue::getTrack 0
May 29 15:18:39 voluxivmio volumio[1175]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf
May 29 15:18:39 voluxivmio volumio[1175]: info: Reading ALSA contributions from plugins.
May 29 15:18:39 voluxivmio volumio[1175]: info: MPD Permissions set
May 29 15:18:39 voluxivmio volumio[1175]: info: MPD Permissions set
May 29 15:18:39 voluxivmio volumio[1175]: info: Upmpdcli Daemon Started
May 29 15:18:39 voluxivmio volumio[1175]: info: Spotify config file written
May 29 15:18:39 voluxivmio volumio[1175]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1
May 29 15:18:39 voluxivmio volumio[1175]: info: Volumio called home
May 29 15:18:39 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:39 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:39 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:39 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:39 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:39 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:39 voluxivmio sudo[1461]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
May 29 15:18:39 voluxivmio sudo[1461]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 15:18:39 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:39 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:39 voluxivmio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
May 29 15:18:39 voluxivmio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
May 29 15:18:39 voluxivmio go-librespot[1464]: go-librespot daemon starting...
May 29 15:18:39 voluxivmio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
May 29 15:18:39 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 29 15:18:39 voluxivmio sudo[1461]: pam_unix(sudo:session): session closed for user root
May 29 15:18:39 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:39 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:39 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:39 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:39 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:39 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:39 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:39 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:39 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:39 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 29 15:18:39 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:39 voluxivmio volumio[1175]: info: No need to fix Spotify hosts
May 29 15:18:39 voluxivmio volumio[1175]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2
May 29 15:18:39 voluxivmio go-librespot[1469]: time="2025-05-29T15:18:39+02:00" level=info msg="running go-librespot 0.2.0"
May 29 15:18:39 voluxivmio go-librespot[1469]: time="2025-05-29T15:18:39+02:00" level=debug msg="app state loaded"
May 29 15:18:39 voluxivmio go-librespot[1469]: time="2025-05-29T15:18:39+02:00" level=debug msg="stored credentials not found"
May 29 15:18:39 voluxivmio go-librespot[1469]: time="2025-05-29T15:18:39+02:00" level=info msg="api server listening on 127.0.0.1:9879"
May 29 15:18:40 voluxivmio volumio[1175]: info: camilladsp service started and running in background, instance 1
May 29 15:18:40 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:40 voluxivmio volumio[1175]: info: FusionDsp - AAAAAAAAAAAAAA-> 44100 48000 96000 <-AAAAAAAAAAAAA
May 29 15:18:40 voluxivmio volumio[1175]: info: FusionDsp loaded
May 29 15:18:40 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
May 29 15:18:40 voluxivmio volumio[1175]: error: FusionDsp - Socket connection not established
May 29 15:18:40 voluxivmio volumio[1175]: info: FusionDsp - Reporting Fusion DSP Enabled
May 29 15:18:40 voluxivmio volumio[1175]: info: Adding Signal Path Element [object Object]
May 29 15:18:40 voluxivmio sudo[1506]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service
May 29 15:18:40 voluxivmio sudo[1506]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 15:18:40 voluxivmio volumio[1175]: info: Adding fusiondspeq DSP Signal Path Element
May 29 15:18:40 voluxivmio volumio[1175]: info: FusionDsp - ---- installed callbackRead
May 29 15:18:40 voluxivmio volumio[1175]: info: FusionDsp - If filter freq >samplerate/2 then disable it
May 29 15:18:40 voluxivmio systemd[1]: Started fusiondsp.service - FusionDsp Daemon.
May 29 15:18:40 voluxivmio sudo[1506]: pam_unix(sudo:session): session closed for user root
May 29 15:18:40 voluxivmio go-librespot[1469]: time="2025-05-29T15:18:40+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
May 29 15:18:40 voluxivmio go-librespot[1469]: time="2025-05-29T15:18:40+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
May 29 15:18:40 voluxivmio go-librespot[1469]: time="2025-05-29T15:18:40+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
May 29 15:18:40 voluxivmio go-librespot[1469]: time="2025-05-29T15:18:40+02:00" level=info msg="zeroconf server listening on port 42837"
May 29 15:18:41 voluxivmio volumio[1175]: error: FusionDsp - Reload WebSocket error: [object Object]
May 29 15:18:41 voluxivmio volumio[1175]: info: Starting Shairport Sync
May 29 15:18:41 voluxivmio volumio[1175]: info: Starting Shairport Sync
May 29 15:18:41 voluxivmio volumio[1175]: info: Starting Shairport Sync
May 29 15:18:41 voluxivmio sudo[1516]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
May 29 15:18:41 voluxivmio sudo[1514]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
May 29 15:18:41 voluxivmio sudo[1514]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 15:18:41 voluxivmio sudo[1516]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 15:18:41 voluxivmio sudo[1518]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
May 29 15:18:41 voluxivmio sudo[1518]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 15:18:41 voluxivmio volumio[1175]: info: Asound.conf file unchanged, so no further update is needed
May 29 15:18:41 voluxivmio volumio[1175]: info: Output device has changed, restarting MPD
May 29 15:18:41 voluxivmio volumio[1175]: info: Output device has changed, restarting Shairport Sync
May 29 15:18:41 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:41 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 29 15:18:41 voluxivmio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
May 29 15:18:41 voluxivmio systemd[1]: shairport-sync.service: Deactivated successfully.
May 29 15:18:41 voluxivmio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
May 29 15:18:41 voluxivmio systemd[1]: shairport-sync.service: Consumed 1.516s CPU time.
May 29 15:18:41 voluxivmio sudo[1523]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
May 29 15:18:41 voluxivmio sudo[1525]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
May 29 15:18:41 voluxivmio sudo[1523]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 15:18:41 voluxivmio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
May 29 15:18:41 voluxivmio volumio[1175]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
May 29 15:18:41 voluxivmio sudo[1514]: pam_unix(sudo:session): session closed for user root
May 29 15:18:41 voluxivmio volumio-remote-updater[714]: [2025-05-29 15:18:41] [connect] Successful connection
May 29 15:18:41 voluxivmio sudo[1525]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 15:18:41 voluxivmio sudo[1516]: pam_unix(sudo:session): session closed for user root
May 29 15:18:41 voluxivmio sudo[1523]: pam_unix(sudo:session): session closed for user root
May 29 15:18:41 voluxivmio sudo[1518]: pam_unix(sudo:session): session closed for user root
May 29 15:18:41 voluxivmio systemd[1]: mpd.service: Deactivated successfully.
May 29 15:18:41 voluxivmio systemd[1]: Stopped mpd.service - Music Player Daemon.
May 29 15:18:41 voluxivmio systemd[1]: mpd.service: Consumed 2.691s CPU time.
May 29 15:18:41 voluxivmio systemd[1]: mpd.socket: Deactivated successfully.
May 29 15:18:41 voluxivmio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
May 29 15:18:41 voluxivmio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
May 29 15:18:41 voluxivmio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
May 29 15:18:41 voluxivmio systemd[1]: Starting mpd.service - Music Player Daemon...
May 29 15:18:41 voluxivmio sudo[1548]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
May 29 15:18:41 voluxivmio sudo[1548]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
May 29 15:18:41 voluxivmio sudo[1549]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory
May 29 15:18:41 voluxivmio sudo[1548]: pam_unix(sudo:session): session closed for user root
May 29 15:18:41 voluxivmio volumio[1175]: error: Upnp client error: Error: read ECONNRESET
May 29 15:18:42 voluxivmio volumio[1175]: error: Upnp client error: Error: read ECONNRESET
May 29 15:18:42 voluxivmio volumio[1175]: info: MPD Permissions set
May 29 15:18:42 voluxivmio volumio[1175]: info: Shairport-Sync Started
May 29 15:18:42 voluxivmio volumio[1175]: Error adding Membership: Error: addMembership EINVAL
May 29 15:18:42 voluxivmio volumio[1175]: info: Shairport-Sync Started
May 29 15:18:42 voluxivmio volumio[1175]: info: Shairport-Sync Started
May 29 15:18:42 voluxivmio volumio-remote-updater[714]: [2025-05-29 15:18:42] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1748524721 101
May 29 15:18:42 voluxivmio volumio[1175]: 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: 3
May 29 15:18:42 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:42 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:42 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:42 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:42 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:42 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:42 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:42 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:42 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 29 15:18:42 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 29 15:18:43 voluxivmio volumio[1175]: info: CoreCommandRouter::volumioGetState
May 29 15:18:43 voluxivmio volumio[1175]: info: CorePlayQueue::getTrack 0
May 29 15:18:43 voluxivmio volumio[1175]: info: Starting Shairport Sync
May 29 15:18:43 voluxivmio volumio[1175]: info: CoreCommandRouter::volumioGetState
May 29 15:18:43 voluxivmio volumio[1175]: info: CorePlayQueue::getTrack 0
May 29 15:18:43 voluxivmio volumio[1175]: info: CoreCommandRouter::volumioPause
May 29 15:18:43 voluxivmio volumio[1175]: info: CoreStateMachine::pause
May 29 15:18:43 voluxivmio volumio[1175]: info: mpdhttpout --- Volumio set on pause
May 29 15:18:43 voluxivmio volumio[1175]: info: mpdhttpout ---Configuration successfully added to mpd.conf.
May 29 15:18:43 voluxivmio sudo[1558]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
May 29 15:18:43 voluxivmio sudo[1558]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 15:18:43 voluxivmio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
May 29 15:18:43 voluxivmio systemd[1]: shairport-sync.service: Deactivated successfully.
May 29 15:18:43 voluxivmio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
May 29 15:18:43 voluxivmio systemd[1]: shairport-sync.service: Consumed 1.330s CPU time.
May 29 15:18:43 voluxivmio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
May 29 15:18:43 voluxivmio sudo[1558]: pam_unix(sudo:session): session closed for user root
May 29 15:18:43 voluxivmio volumio[1175]: info: Shairport-Sync Started
May 29 15:18:43 voluxivmio mpd[1550]: 2025-05-29T15:18:43 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
May 29 15:18:44 voluxivmio volumio[1175]: info: go-librespot daemon successfully initialized
May 29 15:18:44 voluxivmio systemd[1]: Started mpd.service - Music Player Daemon.
May 29 15:18:44 voluxivmio sudo[1423]: pam_unix(sudo:session): session closed for user root
May 29 15:18:44 voluxivmio sudo[1412]: pam_unix(sudo:session): session closed for user root
May 29 15:18:44 voluxivmio sudo[1525]: pam_unix(sudo:session): session closed for user root
May 29 15:18:44 voluxivmio volumio[1175]: error: MPD error: The expression evaluated to a falsy value:
May 29 15:18:44 voluxivmio volumio[1175]: assert.ok(self.idling)
May 29 15:18:44 voluxivmio volumio[1175]: error: The expression evaluated to a falsy value:
May 29 15:18:44 voluxivmio volumio[1175]: assert.ok(self.idling)
May 29 15:18:44 voluxivmio volumio[1175]: error: MPD error: The expression evaluated to a falsy value:
May 29 15:18:44 voluxivmio volumio[1175]: assert.ok(self.idling)
May 29 15:18:44 voluxivmio volumio[1175]: error: The expression evaluated to a falsy value:
May 29 15:18:44 voluxivmio volumio[1175]: assert.ok(self.idling)
May 29 15:18:44 voluxivmio volumio[1175]: info: MPD running with PID1550
May 29 15:18:44 voluxivmio volumio[1175]: ,establishing connection
May 29 15:18:44 voluxivmio volumio[1175]: error: MPD error: The expression evaluated to a falsy value:
May 29 15:18:44 voluxivmio volumio[1175]: assert.ok(self.idling)
May 29 15:18:44 voluxivmio volumio[1175]: error: The expression evaluated to a falsy value:
May 29 15:18:44 voluxivmio volumio[1175]: assert.ok(self.idling)
May 29 15:18:44 voluxivmio volumio[1175]: error: updateQueue error: null
May 29 15:18:44 voluxivmio volumio[1175]: info: [yt-cast-receiver] DIAL server listening on port 8098
May 29 15:18:44 voluxivmio volumio[1175]: info: CoreCommandRouter::volumioRetrievevolume
May 29 15:18:44 voluxivmio volumio[1175]: info: VolumeController:: Volume=25 Mute =false
May 29 15:18:44 voluxivmio volumio[1175]: info: CoreCommandRouter::volumioGetState
May 29 15:18:44 voluxivmio volumio[1175]: info: CorePlayQueue::getTrack 0
May 29 15:18:44 voluxivmio volumio[1175]: info: CoreStateMachine::pushState
May 29 15:18:44 voluxivmio volumio[1175]: info: CorePlayQueue::getTrack 0
May 29 15:18:44 voluxivmio volumio[1175]: info: CoreCommandRouter::volumioPushState
May 29 15:18:45 voluxivmio volumio[1175]: info: Completed starting Core Plugins
May 29 15:18:45 voluxivmio volumio[1175]: info: -------------------------------------------
May 29 15:18:45 voluxivmio volumio[1175]: info: ----- MyVolumio plugins startup ----
May 29 15:18:45 voluxivmio volumio[1175]: info: -------------------------------------------
May 29 15:18:45 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Fetching plans data....
May 29 15:18:45 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd
May 29 15:18:45 voluxivmio sudo[1582]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
May 29 15:18:45 voluxivmio sudo[1582]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 15:18:45 voluxivmio systemd[1]: Stopping mpd.service - Music Player Daemon...
May 29 15:18:45 voluxivmio volumio[1175]: info: CoreCommandRouter::volumioGetState
May 29 15:18:45 voluxivmio volumio[1175]: info: CorePlayQueue::getTrack 0
May 29 15:18:45 voluxivmio systemd[1]: mpd.service: Deactivated successfully.
May 29 15:18:45 voluxivmio systemd[1]: Stopped mpd.service - Music Player Daemon.
May 29 15:18:45 voluxivmio systemd[1]: mpd.service: Consumed 2.240s CPU time.
May 29 15:18:45 voluxivmio systemd[1]: mpd.socket: Deactivated successfully.
May 29 15:18:45 voluxivmio volumio[1175]: error: [ytcr] Error connecting MPD:
May 29 15:18:45 voluxivmio volumio[1175]: (Error) read ECONNRESET
May 29 15:18:45 voluxivmio volumio[1175]: Error: read ECONNRESET
May 29 15:18:45 voluxivmio volumio[1175]: at Pipe.onStreamRead (node:internal/stream_base_commons:217:20)
May 29 15:18:45 voluxivmio volumio[1175]: Retrying in 5 seconds...
May 29 15:18:45 voluxivmio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
May 29 15:18:45 voluxivmio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
May 29 15:18:45 voluxivmio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
May 29 15:18:45 voluxivmio systemd[1]: Starting mpd.service - Music Player Daemon...
May 29 15:18:45 voluxivmio sudo[1585]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
May 29 15:18:45 voluxivmio sudo[1585]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
May 29 15:18:45 voluxivmio sudo[1585]: pam_unix(sudo:session): session closed for user root
May 29 15:18:47 voluxivmio volumio[1175]: info: Initializing connection to go-librespot Websocket
May 29 15:18:47 voluxivmio go-librespot[1469]: time="2025-05-29T15:18:47+02:00" level=debug msg="new websocket client"
May 29 15:18:47 voluxivmio volumio[1175]: info: Connection to go-librespot Websocket established
May 29 15:18:47 voluxivmio mpd[1587]: 2025-05-29T15:18:47 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
May 29 15:18:47 voluxivmio systemd[1]: Started mpd.service - Music Player Daemon.
May 29 15:18:47 voluxivmio sudo[1582]: pam_unix(sudo:session): session closed for user root
May 29 15:18:47 voluxivmio volumio[1175]: error: updateQueue error: null
May 29 15:18:50 voluxivmio volumio[1175]: info: Getting Spotify volume
May 29 15:18:51 voluxivmio volumio[1175]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4
May 29 15:18:55 voluxivmio volumio[1175]: info: CoreCommandRouter::volumioGetState
May 29 15:18:55 voluxivmio volumio[1175]: info: CorePlayQueue::getTrack 0
May 29 15:18:55 voluxivmio volumio[1175]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25
May 29 15:18:55 voluxivmio volumio[1175]: SPOTIFY: SPOTIFY VOLUME undefined
May 29 15:18:55 voluxivmio volumio[1175]: SPOTIFY: VOLUMIO VOLUME 25
May 29 15:18:55 voluxivmio volumio[1175]: info: Aligning Spotify Volume to Volumio Volume
May 29 15:18:55 voluxivmio volumio[1175]: info: CoreCommandRouter::volumioGetState
May 29 15:18:55 voluxivmio volumio[1175]: info: CorePlayQueue::getTrack 0
May 29 15:18:55 voluxivmio volumio[1175]: info: Setting Spotify Volume from Volumio: 25
May 29 15:18:56 voluxivmio upmpdcli[1610]: writing RSA key
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
May 29 15:18:57 voluxivmio volumio[1175]: info: Adding plugin bluetooth to MyMusic Plugins
May 29 15:18:57 voluxivmio volumio[1175]: info: Adding plugin multiroom to MyMusic Plugins
May 29 15:18:57 voluxivmio volumio[1175]: info: Adding plugin metavolumio to MyMusic Plugins
May 29 15:18:57 voluxivmio volumio[1175]: info: Adding plugin cd_controller to MyMusic Plugins
May 29 15:18:57 voluxivmio volumio[1175]: info: Adding plugin smart_inputs to MyMusic Plugins
May 29 15:18:57 voluxivmio volumio[1175]: info: Adding plugin tidalconnect to MyMusic Plugins
May 29 15:18:57 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
May 29 15:18:58 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
May 29 15:18:58 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
May 29 15:18:58 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 29 15:18:58 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 29 15:18:58 voluxivmio volumio[1175]: info: Starting MyVolumio Remote Streaming Endpoints
May 29 15:18:58 voluxivmio volumio[1175]: info: MyVolumio login type: Token
May 29 15:18:58 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
May 29 15:18:58 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
May 29 15:18:59 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
May 29 15:18:59 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
May 29 15:18:59 voluxivmio volumio[1175]: info: Streaming services startup
May 29 15:18:59 voluxivmio volumio[1175]: info: Starting Streaming Daemon
May 29 15:18:59 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
May 29 15:18:59 voluxivmio volumio[1175]: SPOTIFY: SETTING SPOTIFY VOLUME 25
May 29 15:18:59 voluxivmio volumio[1175]: info: Sending Spotify command with payload to local API: /player/volume
May 29 15:18:59 voluxivmio sudo[1615]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
May 29 15:18:59 voluxivmio sudo[1615]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 15:18:59 voluxivmio sudo[1615]: pam_unix(sudo:session): session closed for user root
May 29 15:19:00 voluxivmio volumio[1175]: error: Cannot start Volumio Streaming Daemon
May 29 15:19:00 voluxivmio volumio[1175]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
May 29 15:19:00 voluxivmio volumio[1175]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
May 29 15:19:01 voluxivmio volumio[1175]: error: MyVolumio Custom Token format not valid, refreshing it
May 29 15:19:03 voluxivmio volumio[1175]: info: MyVolumio login type: Token
May 29 15:19:05 voluxivmio volumio[1175]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
May 29 15:19:06 voluxivmio volumio[1175]: info: MyVolumio token set successfully
May 29 15:19:06 voluxivmio volumio[1175]: info: MYVOLUMIO: Adding device
May 29 15:19:06 voluxivmio volumio[1175]: info: MYVOLUMIO: Evaluating Server
May 29 15:19:06 voluxivmio volumio[1175]: info: MyVolumio Plan changed: premium
May 29 15:19:06 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Subscribed plan changed to premium
May 29 15:19:06 voluxivmio volumio[1175]: info: Removing browser output: myVolumio user plan is not superstar
May 29 15:19:06 voluxivmio volumio[1175]: info: Removing audio output:
May 29 15:19:06 voluxivmio volumio[1175]: info: MYVOLUMIO: Adding device
May 29 15:19:06 voluxivmio volumio[1175]: info: MYVOLUMIO: Evaluating Server
May 29 15:19:06 voluxivmio volumio[1175]: info: Remote config written successfully
May 29 15:19:06 voluxivmio volumio[1175]: info: Starting Tunnel 1
May 29 15:19:06 voluxivmio volumio[1175]: info: Starting Tunnel Connection Checker
May 29 15:19:06 voluxivmio volumio[1175]: info: Completed starting MyVolumio Plugin
May 29 15:19:07 voluxivmio volumio[1175]: info: Setting Geolocation for MyVolumio to eu10
May 29 15:19:07 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 29 15:19:07 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 29 15:19:07 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 29 15:19:07 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
May 29 15:19:07 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 29 15:19:07 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
May 29 15:19:07 voluxivmio volumio[1175]: info: Successfully Added MyVolumio device
May 29 15:19:07 voluxivmio volumio[1175]: info: MYVolumio Device enabled
May 29 15:19:07 voluxivmio volumio[1175]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins...
May 29 15:19:07 voluxivmio volumio[1175]: info: MyVolumio status changed
May 29 15:19:07 voluxivmio volumio[1175]: info: Streaming services startup
May 29 15:19:07 voluxivmio volumio[1175]: info: Starting Streaming Daemon
May 29 15:19:07 voluxivmio sudo[1656]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
May 29 15:19:08 voluxivmio sudo[1656]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 29 15:19:08 voluxivmio systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service...
May 29 15:19:08 voluxivmio sudo[1656]: pam_unix(sudo:session): session closed for user root
May 29 15:19:08 voluxivmio dbus-daemon[693]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.24' (uid=0 pid=1666 comm="timedatectl show --property=NTPSynchronized --valu")
May 29 15:19:08 voluxivmio systemd[1]: Starting systemd-timedated.service - Time & Date Service...
May 29 15:19:08 voluxivmio dbus-daemon[693]: [system] Successfully activated service 'org.freedesktop.timedate1'
May 29 15:19:08 voluxivmio systemd[1]: Started systemd-timedated.service - Time & Date Service.
May 29 15:19:08 voluxivmio setdatetime-helper.sh[1661]: Time is not synchronized. Attempting to sync...
May 29 15:19:08 voluxivmio volumio-remote-updater[714]: No test mode
May 29 15:19:08 voluxivmio volumio-remote-updater[714]: Alpha test mode enabled
May 29 15:19:08 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
May 29 15:19:08 voluxivmio volumio[1175]: info: Updating MyVolumio device info
May 29 15:19:08 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 29 15:19:08 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 29 15:19:08 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 29 15:19:08 voluxivmio volumio[1175]: error: Cannot start Volumio Streaming Daemon
May 29 15:19:08 voluxivmio volumio[1175]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
May 29 15:19:08 voluxivmio volumio[1175]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
May 29 15:19:08 voluxivmio volumio[1175]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"NEW ADDITIONS
\n\n- Updater 1.8.12
\n- Release channel selector
\n
\nFIXES
\n\n- Force updater static libs
\n
\n","title":"Update v4.003","updateavailable":true}
May 29 15:19:08 voluxivmio sudo[1684]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Thu, 29 May 2025 13:19:08 GMT#015'
May 29 15:19:08 voluxivmio sudo[1684]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
May 29 15:19:08 voluxivmio setdatetime-helper.sh[1685]: Thu May 29 15:19:08 CEST 2025
May 29 15:19:08 voluxivmio systemd-journald[365]: Time jumped backwards, rotating.
May 29 15:19:08 voluxivmio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully.
May 29 15:19:08 voluxivmio setdatetime-helper.sh[1661]: Time synchronized successfully.
May 29 15:19:08 voluxivmio sudo[1684]: pam_unix(sudo:session): session closed for user root
May 29 15:19:08 voluxivmio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service.
May 29 15:19:08 voluxivmio volumio[1175]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
May 29 15:19:08 voluxivmio volumio[1175]: error: Failed to ping endpoint as1.myvolumio.org : unknown error
May 29 15:19:08 voluxivmio volumio[1175]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
May 29 15:19:08 voluxivmio volumio[1175]: Error: Unable to resolve or reject the same promise twice
May 29 15:19:08 voluxivmio volumio[1175]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43)
May 29 15:19:08 voluxivmio volumio[1175]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32371)
May 29 15:19:08 voluxivmio volumio[1175]: at Socket.emit (node:events:514:28)
May 29 15:19:08 voluxivmio volumio[1175]: at addChunk (node:internal/streams/readable:343:12)
May 29 15:19:08 voluxivmio volumio[1175]: at readableAddChunk (node:internal/streams/readable:316:9)
May 29 15:19:08 voluxivmio volumio[1175]: at Readable.push (node:internal/streams/readable:253:10)
May 29 15:19:08 voluxivmio volumio[1175]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23)
May 29 15:19:08 voluxivmio volumio[1175]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
May 29 15:19:10 voluxivmio sudo[1715]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-05-29 15:18'
May 29 15:19:10 voluxivmio sudo[1715]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)"
NAME="Raspbian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
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="fd567ba9bc0dc34c0403e2d5b72a0f46467d1983"
VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6"
VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a"
VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Fri May 23 08:02:06 UTC 2025"
VOLUMIO_VERSION="0.069"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="76fa67e30b28261e1dc7c3a89e610b9e"