-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Fri 2025-05-02 23:58:50 CEST. -- May 02 23:57:07 volumior systemd-timedated[1175]: Changed local time to Fri May 2 23:57:07 2025 May 02 23:57:07 volumior sudo[1173]: pam_unix(sudo:session): session closed for user root May 02 23:57:07 volumior volumio-time-update[710]: volumio-time-update-util: System time updated successfully. May 02 23:57:07 volumior systemd[1]: Started Volumio Time Update Utility. May 02 23:57:07 volumior volumio[1138]: info: Loading plugin "network"... May 02 23:57:07 volumior volumio[1138]: info: Refreshing Cached IP Addresses May 02 23:57:07 volumior sudo[1177]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 02 23:57:07 volumior sudo[1177]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:07 volumior sudo[1179]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 02 23:57:07 volumior sudo[1177]: pam_unix(sudo:session): session closed for user root May 02 23:57:07 volumior sudo[1179]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:07 volumior sudo[1179]: pam_unix(sudo:session): session closed for user root May 02 23:57:07 volumior volumio[1138]: info: Loading plugin "services"... May 02 23:57:07 volumior volumio[1138]: info: Loading plugin "alsa_controller"... May 02 23:57:07 volumior sudo[1188]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 02 23:57:07 volumior sudo[1188]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:07 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 02 23:57:07 volumior volumio[1138]: info: Loading plugin "wizard"... May 02 23:57:07 volumior volumio[1138]: info: Loading plugin "networkfs"... May 02 23:57:07 volumior volumio[1138]: info: Starting Udev Watcher for removable devices May 02 23:57:07 volumior sudo[1205]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.0.101/Multimedia/Musica/Wav /mnt/NAS/NAS May 02 23:57:07 volumior sudo[1205]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:07 volumior volumio[1138]: info: Ignoring mount for partition: boot May 02 23:57:07 volumior volumio[1138]: info: Ignoring mount for partition: volumio May 02 23:57:07 volumior volumio[1138]: info: Ignoring mount for partition: volumio_data May 02 23:57:07 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 02 23:57:07 volumior volumio[1138]: info: Loading plugin "volumio_command_line_client"... May 02 23:57:07 volumior volumio[1138]: info: Loading plugin "upnp"... May 02 23:57:07 volumior volumio[1138]: info: [1746223027688] Starting Upmpd Daemon May 02 23:57:07 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 02 23:57:07 volumior volumio[1138]: info: Loading plugin "my_music"... May 02 23:57:07 volumior volumio[1138]: info: Loading plugin "mpd"... May 02 23:57:07 volumior ntpd[1127]: Soliciting pool server 185.198.109.227 May 02 23:57:07 volumior ntpd[1127]: Soliciting pool server 178.215.228.24 May 02 23:57:07 volumior ntpd[1127]: Soliciting pool server 83.97.79.109 May 02 23:57:07 volumior ntpd[1127]: Soliciting pool server 162.159.200.123 May 02 23:57:07 volumior kernel: Key type cifs.spnego registered May 02 23:57:07 volumior kernel: Key type cifs.idmap registered May 02 23:57:07 volumior kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. May 02 23:57:07 volumior kernel: CIFS: Attempting to mount //192.168.0.101/Multimedia/Musica/Wav May 02 23:57:07 volumior nmbd[862]: [2025/05/02 23:57:07.974880, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 02 23:57:07 volumior systemd[1]: Started Samba NMB Daemon. May 02 23:57:08 volumior volumio[1138]: info: Loading plugin "upnp_browser"... May 02 23:57:07 volumior nmbd[862]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections May 02 23:57:08 volumior systemd[1]: Starting Samba Winbind Daemon... May 02 23:57:08 volumior kernel: cryptd: max_cpu_qlen set to 1000 May 02 23:57:08 volumior winbindd[1226]: [2025/05/02 23:57:08.266686, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) May 02 23:57:08 volumior winbindd[1226]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 May 02 23:57:08 volumior sudo[1205]: pam_unix(sudo:session): session closed for user root May 02 23:57:08 volumior kernel: CIFS: VFS: \\192.168.0.101 failed to connect to IPC (rc=-13) May 02 23:57:08 volumior kernel: CIFS: VFS: session 780b726f has no tcon available for a dfs referral request May 02 23:57:08 volumior kernel: CIFS: VFS: cifs_mount failed w/return code = -13 May 02 23:57:08 volumior systemd[1]: Started Samba Winbind Daemon. May 02 23:57:08 volumior winbindd[1226]: [2025/05/02 23:57:08.319036, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 02 23:57:08 volumior volumio[1138]: info: Loading plugin "alarm-clock"... May 02 23:57:08 volumior winbindd[1226]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections May 02 23:57:08 volumior systemd[1]: Starting Samba SMB Daemon... May 02 23:57:08 volumior volumio[1138]: info: Loading plugin "airplay_emulation"... May 02 23:57:08 volumior volumio[1138]: info: Starting Shairport Sync May 02 23:57:08 volumior volumio[1138]: info: Loading plugin "last_100"... May 02 23:57:08 volumior volumio[1138]: info: Loading plugin "webradio"... May 02 23:57:08 volumior volumio[1138]: info: Loading plugin "i2s_dacs"... May 02 23:57:08 volumior volumio[1138]: info: Loading plugin "volumiodiscovery"... May 02 23:57:08 volumior volumio[1138]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 02 23:57:08 volumior volumio[1138]: *** WARNING *** Please fix your application to use the native API of Avahi! May 02 23:57:08 volumior volumio[1138]: *** WARNING *** For more information see May 02 23:57:08 volumior node[1138]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 02 23:57:08 volumior volumio[1138]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 02 23:57:08 volumior volumio[1138]: *** WARNING *** Please fix your application to use the native API of Avahi! May 02 23:57:08 volumior volumio[1138]: *** WARNING *** For more information see May 02 23:57:08 volumior node[1138]: *** WARNING *** Please fix your application to use the native API of Avahi! May 02 23:57:08 volumior node[1138]: *** WARNING *** For more information see May 02 23:57:08 volumior node[1138]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 02 23:57:08 volumior node[1138]: *** WARNING *** Please fix your application to use the native API of Avahi! May 02 23:57:08 volumior node[1138]: *** WARNING *** For more information see May 02 23:57:08 volumior ntpd[1127]: Soliciting pool server 5.250.184.159 May 02 23:57:08 volumior ntpd[1127]: Soliciting pool server 84.77.195.114 May 02 23:57:08 volumior ntpd[1127]: Soliciting pool server 5.250.184.159 May 02 23:57:08 volumior volumio[1138]: info: Applying required configuration parameters for plugin volumiodiscovery May 02 23:57:08 volumior volumio[1138]: info: Discovery: Started advertising with name: Volumior May 02 23:57:08 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 02 23:57:08 volumior volumio[1138]: info: Loading plugin "spop"... May 02 23:57:08 volumior smbd[1248]: [2025/05/02 23:57:08.788641, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 02 23:57:08 volumior systemd[1]: Started Samba SMB Daemon. May 02 23:57:08 volumior smbd[1248]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections May 02 23:57:08 volumior systemd[1]: Reached target Multi-User System. May 02 23:57:08 volumior systemd[1]: Reached target Graphical Interface. May 02 23:57:08 volumior systemd[1]: Starting Update UTMP about System Runlevel Changes... May 02 23:57:08 volumior systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. May 02 23:57:08 volumior systemd[1]: Started Update UTMP about System Runlevel Changes. May 02 23:57:08 volumior systemd[1]: Startup finished in 13.122s (kernel) + 26.367s (userspace) = 39.490s. May 02 23:57:08 volumior volumio-remote-updater[707]: [2025-05-02 23:57:08] [connect] Successful connection May 02 23:57:09 volumior ntpd[1127]: Soliciting pool server 90.68.206.60 May 02 23:57:09 volumior ntpd[1127]: Soliciting pool server 2001:ba0:21f:4900::1 May 02 23:57:09 volumior volumio[1138]: info: Loading plugin "outputs"... May 02 23:57:09 volumior volumio[1138]: info: Loading plugin "albumart"... May 02 23:57:09 volumior volumio[1138]: info: Plugin example_plugin is not enabled May 02 23:57:09 volumior volumio[1138]: info: Loading plugin "inputs"... May 02 23:57:09 volumior volumio[1138]: info: Loading plugin "updater_comm"... May 02 23:57:10 volumior volumio[1138]: info: Plugin mpdemulation is not enabled May 02 23:57:10 volumior volumio[1138]: info: Loading plugin "rest_api"... May 02 23:57:10 volumior volumio[1138]: info: Loading plugin "websocket"... May 02 23:57:10 volumior volumio[1138]: info: Starting Socket.io Server version 2.3.0 May 02 23:57:10 volumior volumio[1138]: info: Loading plugin "fusiondsp"... May 02 23:57:10 volumior volumio[1138]: Forking 3 albumart workers May 02 23:57:10 volumior volumio[1138]: info: Applying required configuration parameters for plugin fusiondsp May 02 23:57:10 volumior volumio[1138]: info: Loading plugin "minidlna"... May 02 23:57:10 volumior volumio[1138]: info: Applying required configuration parameters for plugin minidlna May 02 23:57:10 volumior volumio[1138]: info: Loading plugin "music_services_shield"... May 02 23:57:10 volumior volumio[1138]: Starting albumart workers May 02 23:57:10 volumior ntpd[1127]: Soliciting pool server 195.95.153.59 May 02 23:57:10 volumior volumio[1138]: Starting albumart workers May 02 23:57:10 volumior volumio[1138]: Starting albumart workers May 02 23:57:11 volumior volumio[1138]: info: Applying required configuration parameters for plugin music_services_shield May 02 23:57:11 volumior volumio[1138]: info: Loading plugin "peppymeterbasic"... May 02 23:57:11 volumior sudo[1188]: pam_unix(sudo:session): session closed for user root May 02 23:57:11 volumior volumio[1138]: info: Loading plugin "peppyspectrum"... May 02 23:57:11 volumior ntpd[1127]: Soliciting pool server 208.85.20.220 May 02 23:57:11 volumior volumio[1138]: info: Loading i18n strings for locale es May 02 23:57:11 volumior volumio[1138]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. May 02 23:57:11 volumior volumio[1138]: info: Plugin peppymeterbasic has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. May 02 23:57:11 volumior volumio[1138]: info: Plugin peppymeterbasic has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. May 02 23:57:11 volumior volumio[1138]: info: Plugin peppyspectrum has duplicated i18n key LOCALSETTINGS. It is ignored. May 02 23:57:11 volumior volumio[1138]: info: Plugin peppyspectrum has duplicated i18n key SCREENSIZE. It is ignored. May 02 23:57:11 volumior volumio[1138]: info: Plugin peppyspectrum has duplicated i18n key SCREENSIZE_DOC. It is ignored. May 02 23:57:11 volumior volumio[1138]: info: Plugin peppyspectrum has duplicated i18n key NBARCHANGE. It is ignored. May 02 23:57:11 volumior volumio[1138]: info: Plugin peppyspectrum has duplicated i18n key APLICAR. It is ignored. May 02 23:57:11 volumior volumio[1138]: info: Plugin peppyspectrum has duplicated i18n key GUARDAR. It is ignored. May 02 23:57:11 volumior volumio[1138]: info: Plugin peppyspectrum has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. May 02 23:57:11 volumior volumio[1138]: info: Plugin peppyspectrum has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. May 02 23:57:11 volumior volumio[1138]: info: Plugin peppyspectrum has duplicated i18n key LIST_FAIL_UPDATE. It is ignored. May 02 23:57:11 volumior volumio[1138]: Updating browse sources language May 02 23:57:11 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 02 23:57:11 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 02 23:57:11 volumior volumio[1138]: info: CoreCommandRouter::initPlayerControls May 02 23:57:11 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:11 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:11 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:11 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:11 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:11 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:11 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:11 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:11 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 02 23:57:11 volumior volumio[1138]: Express server listening on port 3000 May 02 23:57:11 volumior volumio[1138]: [Metrics] WebUI: 6s 895.04ms May 02 23:57:12 volumior volumio[1138]: info: CoreStateMachine::resetVolumioState May 02 23:57:12 volumior volumio[1138]: info: CoreStateMachine::getcurrentVolume May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::volumioRetrievevolume May 02 23:57:12 volumior volumio[1138]: info: Volumio Network Manager: Network status updated: 2 May 02 23:57:12 volumior volumio[1138]: info: Cannot mount NAS NAS at system boot, trial number 1 ,retrying in 5 seconds May 02 23:57:12 volumior volumio[1138]: verbose: New Socket.io Connection to 192.168.0.123 from 192.168.0.114 UA: Mozilla/5.0 (Linux; Android 14; SM-G998B Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.60 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 May 02 23:57:12 volumior volumio[1138]: verbose: New Socket.io Connection to 192.168.0.123 from 192.168.0.114 UA: Mozilla/5.0 (Linux; Android 14; SM-G998B Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.60 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 May 02 23:57:12 volumior volumio-remote-updater[707]: [2025-05-02 23:57:12] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1746223028 101 May 02 23:57:12 volumior volumio[1138]: 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 02 23:57:12 volumior volumio[1138]: verbose: New Socket.io Connection to 192.168.0.123 from 192.168.0.114 UA: Mozilla/5.0 (Linux; Android 14; SM-G998B Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.60 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:12 volumior volumio[1138]: info: Reloading queue from file May 02 23:57:12 volumior volumio[1138]: info: CoreStateMachine::setRepeat null single undefined May 02 23:57:12 volumior volumio[1138]: info: CoreStateMachine::pushState May 02 23:57:12 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::volumioPushState May 02 23:57:12 volumior volumio[1138]: info: CoreStateMachine::setRandom true May 02 23:57:12 volumior volumio[1138]: info: CoreStateMachine::pushState May 02 23:57:12 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::volumioPushState May 02 23:57:12 volumior volumio[1138]: info: Setting Device type: Raspberry PI May 02 23:57:12 volumior volumio[1138]: info: Completed loading Core Plugins May 02 23:57:12 volumior volumio[1138]: info: Preparing to generate the ALSA configuration file May 02 23:57:12 volumior volumio[1138]: info: VolumeController:: Volume=50 Mute =false May 02 23:57:12 volumior volumio[1138]: info: CoreStateMachine::pushState May 02 23:57:12 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::volumioPushState May 02 23:57:12 volumior volumio[1138]: info: CoreStateMachine::updateTrackBlock May 02 23:57:12 volumior volumio[1138]: info: CorePlayQueue::getTrackBlock May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::volumioRetrievevolume May 02 23:57:12 volumior volumio[1138]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb May 02 23:57:12 volumior volumio[1138]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03115 May 02 23:57:12 volumior volumio[1138]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI May 02 23:57:12 volumior volumio[1138]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 02 23:57:12 volumior volumio[1138]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf May 02 23:57:12 volumior volumio[1138]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf May 02 23:57:12 volumior volumio[1138]: info: Reading ALSA contributions from plugins. May 02 23:57:12 volumior volumio[1138]: info: Asound.conf file written May 02 23:57:12 volumior sudo[1326]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf May 02 23:57:12 volumior sudo[1326]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:12 volumior sudo[1326]: pam_unix(sudo:session): session closed for user root May 02 23:57:12 volumior volumio[1138]: info: Output device has changed, restarting MPD May 02 23:57:12 volumior sudo[1331]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 02 23:57:12 volumior sudo[1331]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:12 volumior volumio[1138]: info: Output device has changed, restarting Shairport Sync May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:12 volumior sudo[1331]: pam_unix(sudo:session): session closed for user root May 02 23:57:12 volumior sudo[1334]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 02 23:57:12 volumior sudo[1334]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:12 volumior systemd[1]: musicservicesshield.service: Succeeded. May 02 23:57:12 volumior systemd[1]: Stopped Shield Volumio Music Services in the User CPU Set. May 02 23:57:12 volumior systemd[1]: Stopping Shield Volumio Music Services in the User CPU Set... May 02 23:57:12 volumior systemd[1]: Stopping Music Player Daemon... May 02 23:57:12 volumior volumio[1138]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 02 23:57:12 volumior volumio[1138]: info: ___________ START PLUGINS ___________ May 02 23:57:12 volumior volumio[1138]: info: ControllerMpd::onStart: Initializing MPD May 02 23:57:12 volumior volumio[1138]: info: Creating MPD Configuration file May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 02 23:57:12 volumior volumio[1138]: info: [1746223032466] CoreMusicLibrary::Adding element Media Servers May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 02 23:57:12 volumior sudo[1340]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 02 23:57:12 volumior sudo[1340]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:12 volumior sudo[1340]: pam_unix(sudo:session): session closed for user root May 02 23:57:12 volumior sudo[1342]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 02 23:57:12 volumior sudo[1342]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:12 volumior systemd[1]: mpd.service: Succeeded. May 02 23:57:12 volumior systemd[1]: Stopped Music Player Daemon. May 02 23:57:12 volumior volumio[1138]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:12 volumior volumio[1138]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 02 23:57:12 volumior volumio[1138]: info: [1746223032562] CoreMusicLibrary::Adding element Last_100 May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 02 23:57:12 volumior volumio[1138]: info: [1746223032564] CoreMusicLibrary::Adding element Webradio May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 02 23:57:12 volumior volumio[1138]: info: Initializing BBC Radios May 02 23:57:12 volumior systemd[1]: Starting Music Player Daemon... May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:12 volumior volumio[1138]: info: Creating Spotify config file May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:12 volumior sudo[1348]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 02 23:57:12 volumior sudo[1348]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:12 volumior sudo[1348]: pam_unix(sudo:session): session closed for user root May 02 23:57:12 volumior volumio[1138]: info: Loading i18n strings for locale es May 02 23:57:12 volumior volumio[1138]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. May 02 23:57:12 volumior volumio[1138]: info: Plugin peppymeterbasic has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. May 02 23:57:12 volumior volumio[1138]: info: Plugin peppymeterbasic has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. May 02 23:57:12 volumior volumio[1138]: info: Plugin peppyspectrum has duplicated i18n key LOCALSETTINGS. It is ignored. May 02 23:57:12 volumior volumio[1138]: info: Plugin peppyspectrum has duplicated i18n key SCREENSIZE. It is ignored. May 02 23:57:12 volumior volumio[1138]: info: Plugin peppyspectrum has duplicated i18n key SCREENSIZE_DOC. It is ignored. May 02 23:57:12 volumior volumio[1138]: info: Plugin peppyspectrum has duplicated i18n key NBARCHANGE. It is ignored. May 02 23:57:12 volumior volumio[1138]: info: Plugin peppyspectrum has duplicated i18n key APLICAR. It is ignored. May 02 23:57:12 volumior volumio[1138]: info: Plugin peppyspectrum has duplicated i18n key GUARDAR. It is ignored. May 02 23:57:12 volumior volumio[1138]: info: Plugin peppyspectrum has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. May 02 23:57:12 volumior volumio[1138]: info: Plugin peppyspectrum has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. May 02 23:57:12 volumior volumio[1138]: info: Plugin peppyspectrum has duplicated i18n key LIST_FAIL_UPDATE. It is ignored. May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:12 volumior volumio[1138]: info: FusionDsp - mixtype--------------------- Hardware May 02 23:57:12 volumior volumio[1138]: info: Loading i18n strings for locale es May 02 23:57:12 volumior volumio[1138]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. May 02 23:57:12 volumior volumio[1138]: info: Plugin peppymeterbasic has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. May 02 23:57:12 volumior volumio[1138]: info: Plugin peppymeterbasic has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. May 02 23:57:12 volumior volumio[1138]: info: Plugin peppyspectrum has duplicated i18n key LOCALSETTINGS. It is ignored. May 02 23:57:12 volumior volumio[1138]: info: Plugin peppyspectrum has duplicated i18n key SCREENSIZE. It is ignored. May 02 23:57:12 volumior volumio[1138]: info: Plugin peppyspectrum has duplicated i18n key SCREENSIZE_DOC. It is ignored. May 02 23:57:12 volumior volumio[1138]: info: Plugin peppyspectrum has duplicated i18n key NBARCHANGE. It is ignored. May 02 23:57:12 volumior volumio[1138]: info: Plugin peppyspectrum has duplicated i18n key APLICAR. It is ignored. May 02 23:57:12 volumior volumio[1138]: info: Plugin peppyspectrum has duplicated i18n key GUARDAR. It is ignored. May 02 23:57:12 volumior volumio[1138]: info: Plugin peppyspectrum has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. May 02 23:57:12 volumior volumio[1138]: info: Plugin peppyspectrum has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. May 02 23:57:12 volumior volumio[1138]: info: Plugin peppyspectrum has duplicated i18n key LIST_FAIL_UPDATE. It is ignored. May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile May 02 23:57:12 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile May 02 23:57:12 volumior volumio[1138]: info: Volumio Calling Home May 02 23:57:12 volumior sudo[1392]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/moveallprocesses.sh May 02 23:57:12 volumior sudo[1392]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:13 volumior volumio[1138]: info: Preparing to generate the ALSA configuration file May 02 23:57:13 volumior volumio[1138]: info: Discovery: adding 3f8f53fb-ae49-442c-838a-a63859645d32 May 02 23:57:13 volumior volumio[1138]: info: Discovery: Found device Volumior May 02 23:57:13 volumior volumio[1138]: info: CoreCommandRouter::volumioGetState May 02 23:57:13 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:57:13 volumior volumio[1138]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 02 23:57:13 volumior volumio[1138]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf May 02 23:57:13 volumior volumio[1138]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf May 02 23:57:13 volumior volumio[1138]: info: Reading ALSA contributions from plugins. May 02 23:57:13 volumior volumio[1138]: verbose: New Socket.io Connection to 192.168.0.123 from 192.168.0.114 UA: Mozilla/5.0 (Linux; Android 14; SM-G998B Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.60 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 May 02 23:57:13 volumior volumio[1138]: verbose: New Socket.io Connection to 192.168.0.123 from 192.168.0.114 UA: Mozilla/5.0 (Linux; Android 14; SM-G998B Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.60 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 May 02 23:57:13 volumior volumio[1138]: info: minidlna: Found miniDLNA version 1.2.1 May 02 23:57:13 volumior volumio[1138]: info: MPD Permissions set May 02 23:57:13 volumior volumio[1138]: info: MPD Permissions set May 02 23:57:13 volumior volumio[1138]: info: Spotify config file written May 02 23:57:13 volumior sudo[1409]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 02 23:57:13 volumior sudo[1409]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:13 volumior volumio[1138]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 May 02 23:57:13 volumior volumio[1138]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 May 02 23:57:13 volumior volumio[1138]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 May 02 23:57:13 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:13 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:13 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:13 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:13 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:13 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:13 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:13 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:13 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:13 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:13 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:13 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:13 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:13 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:13 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:13 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:13 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:13 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:13 volumior systemd[1]: Started go-librespot Daemon. May 02 23:57:13 volumior go-librespot[1412]: go-librespot daemon starting... May 02 23:57:13 volumior sudo[1409]: pam_unix(sudo:session): session closed for user root May 02 23:57:13 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:13 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:13 volumior volumio[1138]: info: No need to fix Spotify hosts May 02 23:57:13 volumior sudo[1392]: pam_unix(sudo:session): session closed for user root May 02 23:57:13 volumior volumio[1138]: info: Volumio called home May 02 23:57:13 volumior volumio[1138]: info: VolumeController:: Volume=50 Mute =false May 02 23:57:13 volumior volumio[1138]: info: CoreStateMachine::pushState May 02 23:57:13 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:57:13 volumior volumio[1138]: info: CoreCommandRouter::volumioPushState May 02 23:57:13 volumior mpd[1363]: May 02 23:57 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 02 23:57:13 volumior systemd[1]: Started Music Player Daemon. May 02 23:57:13 volumior sudo[1342]: pam_unix(sudo:session): session closed for user root May 02 23:57:13 volumior sudo[1334]: pam_unix(sudo:session): session closed for user root May 02 23:57:13 volumior volumio[1138]: info: Starting Shairport Sync May 02 23:57:13 volumior sudo[1434]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/addservice.sh May 02 23:57:13 volumior sudo[1434]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:13 volumior volumio[1138]: info: Starting Shairport Sync May 02 23:57:13 volumior systemd[1]: Starting Shield Volumio Music Services in the User CPU Set... May 02 23:57:13 volumior sudo[1440]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 02 23:57:13 volumior sudo[1440]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:13 volumior volumio[1138]: info: Starting Shairport Sync May 02 23:57:13 volumior sudo[1448]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 02 23:57:13 volumior sudo[1448]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:13 volumior systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 02 23:57:13 volumior systemd[1]: shairport-sync.service: Succeeded. May 02 23:57:13 volumior systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 02 23:57:13 volumior systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 02 23:57:13 volumior volumio[1138]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ May 02 23:57:13 volumior volumio[1138]: SPOTIFY: BQDWAHtPEnWafON9ik0to8UF2Qlh3rRHhxaPlKcXqJWU4RcJIvY-B0R9Lp3vuSOotDG0q73o3zNsc2O23Kpj3khqOFJBKrd-lkOWNoLqNQNz9vdec3BrdzMi1NIqXWZ_bS3xbDZIDWtkfINP03m2QYcFvIZ_7nVzRV3j6IR97-r5mepDOYs2VKUTnd0CqxnMfQKmZ4Q0Z8RdlNvM-QGlFLjHOxCNKTH4vG0oaRBefgtpmt44UKC1-1lI5tlylj1hn1KEv3US1GwCeubV0Rvj3VzzoBOG_Cwc41IDCUEtzQI May 02 23:57:13 volumior volumio[1138]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ May 02 23:57:13 volumior volumio[1138]: info: New Spotify access token = BQDWAHtPEnWafON9ik0to8UF2Qlh3rRHhxaPlKcXqJWU4RcJIvY-B0R9Lp3vuSOotDG0q73o3zNsc2O23Kpj3khqOFJBKrd-lkOWNoLqNQNz9vdec3BrdzMi1NIqXWZ_bS3xbDZIDWtkfINP03m2QYcFvIZ_7nVzRV3j6IR97-r5mepDOYs2VKUTnd0CqxnMfQKmZ4Q0Z8RdlNvM-QGlFLjHOxCNKTH4vG0oaRBefgtpmt44UKC1-1lI5tlylj1hn1KEv3US1GwCeubV0Rvj3VzzoBOG_Cwc41IDCUEtzQI May 02 23:57:13 volumior volumio[1138]: info: Spotify credentials grant success - running version from March 24, 2019 May 02 23:57:13 volumior sudo[1440]: pam_unix(sudo:session): session closed for user root May 02 23:57:13 volumior systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 02 23:57:13 volumior systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM May 02 23:57:13 volumior systemd[1]: shairport-sync.service: Succeeded. May 02 23:57:13 volumior systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 02 23:57:13 volumior sudo[1456]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 02 23:57:13 volumior systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 02 23:57:13 volumior sudo[1456]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:13 volumior sudo[1448]: pam_unix(sudo:session): session closed for user root May 02 23:57:13 volumior volumio[1138]: info: CoreCommandRouter::volumioGetState May 02 23:57:13 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:57:13 volumior systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 02 23:57:13 volumior systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM May 02 23:57:13 volumior systemd[1]: shairport-sync.service: Succeeded. May 02 23:57:13 volumior systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 02 23:57:13 volumior systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 02 23:57:14 volumior ntpd[1127]: receive: Unexpected origin timestamp 0xebbfbe39.bb5af822 does not match aorg 0000000000.00000000 from server@94.143.139.219 xmt 0xebbfbe3a.4f574566 May 02 23:57:14 volumior ntpd[1127]: receive: Unexpected origin timestamp 0xebbfbe39.bb5729b5 does not match aorg 0000000000.00000000 from server@5.250.184.159 xmt 0xebbfbe3a.4f59b2b0 May 02 23:57:14 volumior ntpd[1127]: receive: Unexpected origin timestamp 0xebbfbe39.bb5a0571 does not match aorg 0000000000.00000000 from server@217.160.115.110 xmt 0xebbfbe3a.4fbadaaa May 02 23:57:14 volumior sudo[1456]: pam_unix(sudo:session): session closed for user root May 02 23:57:14 volumior ntpd[1127]: receive: Unexpected origin timestamp 0xebbfbe39.bb517c43 does not match aorg 0000000000.00000000 from server@90.68.206.60 xmt 0xebbfbe3a.5022f9e4 May 02 23:57:14 volumior go-librespot[1412]: time="2025-05-02T23:57:14+02:00" level=info msg="running go-librespot 0.2.0" May 02 23:57:14 volumior ntpd[1127]: receive: Unexpected origin timestamp 0xebbfbe39.bb55c655 does not match aorg 0000000000.00000000 from server@84.77.195.114 xmt 0xebbfbe3a.515ab976 May 02 23:57:14 volumior ntpd[1127]: receive: Unexpected origin timestamp 0xebbfbe39.bb581fd1 does not match aorg 0000000000.00000000 from server@178.215.228.24 xmt 0xebbfbe3a.52563c1e May 02 23:57:14 volumior go-librespot[1412]: time="2025-05-02T23:57:14+02:00" level=debug msg="app state loaded" May 02 23:57:14 volumior volumio[1138]: info: minidlna: /data/minidlna.conf written May 02 23:57:14 volumior volumio[1138]: info: minidlna: Starting minidlna.service May 02 23:57:14 volumior go-librespot[1412]: time="2025-05-02T23:57:14+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 02 23:57:14 volumior sudo[1466]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start minidlna.service May 02 23:57:14 volumior sudo[1466]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:14 volumior volumio[1138]: error: MPD error: The expression evaluated to a falsy value: May 02 23:57:14 volumior volumio[1138]: assert.ok(self.idling) May 02 23:57:14 volumior volumio[1138]: error: The expression evaluated to a falsy value: May 02 23:57:14 volumior volumio[1138]: assert.ok(self.idling) May 02 23:57:14 volumior systemd[1]: Started MiniDLNA lightweight DLNA/UPnP-AV server. May 02 23:57:14 volumior sudo[1466]: pam_unix(sudo:session): session closed for user root May 02 23:57:14 volumior volumio[1138]: info: Shairport-Sync Started May 02 23:57:14 volumior volumio[1138]: Error adding Membership: Error: addMembership EINVAL May 02 23:57:14 volumior volumio[1138]: info: Shairport-Sync Started May 02 23:57:14 volumior volumio[1138]: info: Shairport-Sync Started May 02 23:57:14 volumior volumio[1138]: info: MPD running with PID1363 May 02 23:57:14 volumior volumio[1138]: ,establishing connection May 02 23:57:14 volumior volumio[1138]: info: Asound.conf file unchanged, so no further update is needed May 02 23:57:14 volumior volumio[1138]: info: Output device has changed, restarting MPD May 02 23:57:14 volumior sudo[1474]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 02 23:57:14 volumior sudo[1474]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:14 volumior sudo[1474]: pam_unix(sudo:session): session closed for user root May 02 23:57:14 volumior volumio[1138]: info: Output device has changed, restarting Shairport Sync May 02 23:57:14 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:14 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:14 volumior sudo[1477]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 02 23:57:14 volumior sudo[1477]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:14 volumior volumio[1435]: cset: --> shielding system active with May 02 23:57:14 volumior volumio[1435]: cset: "system" cpuset of CPUSPEC(1-3) with 118 tasks running May 02 23:57:14 volumior volumio[1435]: cset: "user" cpuset of CPUSPEC(0) with 3 tasks running May 02 23:57:14 volumior systemd[1]: Stopping Music Player Daemon... May 02 23:57:14 volumior systemd[1]: Started Shield Volumio Music Services in the User CPU Set. May 02 23:57:14 volumior systemd[1]: mpd.service: Succeeded. May 02 23:57:14 volumior systemd[1]: Stopped Music Player Daemon. May 02 23:57:14 volumior volumio[1138]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 02 23:57:14 volumior volumio[1138]: info: Preparing to generate the ALSA configuration file May 02 23:57:14 volumior systemd[1]: Starting Music Player Daemon... May 02 23:57:14 volumior volumio[1138]: error: updateQueue error: null May 02 23:57:14 volumior systemd[1]: Reloading. May 02 23:57:14 volumior go-librespot[1412]: time="2025-05-02T23:57:14+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" May 02 23:57:14 volumior go-librespot[1412]: time="2025-05-02T23:57:14+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 02 23:57:14 volumior go-librespot[1412]: time="2025-05-02T23:57:14+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 02 23:57:14 volumior go-librespot[1412]: time="2025-05-02T23:57:14+02:00" level=info msg="zeroconf server listening on port 45459" May 02 23:57:14 volumior sudo[1483]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 02 23:57:14 volumior sudo[1483]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:14 volumior sudo[1483]: pam_unix(sudo:session): session closed for user root May 02 23:57:14 volumior volumio[1138]: info: minidlna: systemctl start minidlna.service succeeded. May 02 23:57:14 volumior volumio[1138]: info: Completed starting Core Plugins May 02 23:57:14 volumior volumio[1138]: info: ------------------------------------------- May 02 23:57:14 volumior volumio[1138]: info: ----- MyVolumio plugins startup ---- May 02 23:57:14 volumior volumio[1138]: info: ------------------------------------------- May 02 23:57:14 volumior volumio[1138]: info: [MyVolumio PluginManager] Fetching plans data.... May 02 23:57:14 volumior volumio[1138]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 02 23:57:14 volumior volumio[1138]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf May 02 23:57:14 volumior volumio[1138]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf May 02 23:57:14 volumior volumio[1138]: info: Reading ALSA contributions from plugins. May 02 23:57:14 volumior volumio[1138]: error: MPD error: Error: write EPIPE May 02 23:57:14 volumior volumio[1138]: error: write EPIPE {"errno":-32,"code":"EPIPE","syscall":"write"} May 02 23:57:14 volumior volumio[1138]: info: MPD Permissions set May 02 23:57:14 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:14 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:14 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:14 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:14 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:14 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:14 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:14 volumior go-librespot[1412]: time="2025-05-02T23:57:14+02:00" level=debug msg="obtained new client token: AACf/NroEq5YjQTdefPVOscdjzttyz2TnDjU5vBosdYau/MjOdlwgLaE2f65O0poT5QUhKVo/FrVPe3qH2Wy8zumjaFuXmAvb7xxR+WLv1cNQ7Jad6pzO8FWc2+XkWNEpaltR9MS6X54jof2ES8t8dHvtNgUBcSo4wFtm/0QVoXtoSr1XonIPDyj9cuXH4LCA2FK7eAoJU5zOk2SYjPq1v2Gb7/qmQAS5U5t6xv1iJkskZR4VmfWJnFB" May 02 23:57:14 volumior volumio[1138]: info: Starting Shairport Sync May 02 23:57:14 volumior sudo[1509]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 02 23:57:14 volumior volumio[1138]: info: Asound.conf file unchanged, so no further update is needed May 02 23:57:14 volumior volumio[1138]: info: Output device has changed, restarting MPD May 02 23:57:14 volumior go-librespot[1412]: time="2025-05-02T23:57:14+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" May 02 23:57:14 volumior sudo[1509]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:14 volumior volumio[1138]: info: Output device has changed, restarting Shairport Sync May 02 23:57:14 volumior sudo[1512]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 02 23:57:14 volumior sudo[1512]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:14 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:14 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:14 volumior sudo[1512]: pam_unix(sudo:session): session closed for user root May 02 23:57:14 volumior go-librespot[1412]: time="2025-05-02T23:57:14+02:00" level=debug msg="completed keyexchange" May 02 23:57:14 volumior go-librespot[1412]: time="2025-05-02T23:57:14+02:00" level=debug msg="completed challenge" May 02 23:57:14 volumior sudo[1514]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 02 23:57:14 volumior sudo[1514]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:15 volumior systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. May 02 23:57:15 volumior volumio[1138]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 02 23:57:15 volumior volumio[1138]: info: Preparing to generate the ALSA configuration file May 02 23:57:15 volumior go-librespot[1412]: time="2025-05-02T23:57:15+02:00" level=info msg="authenticated AP as 31xfvtnrbmt6ansibhk5tw7q544i" May 02 23:57:15 volumior volumio[1138]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 02 23:57:15 volumior volumio[1138]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf May 02 23:57:15 volumior volumio[1138]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf May 02 23:57:15 volumior volumio[1138]: info: Reading ALSA contributions from plugins. May 02 23:57:15 volumior volumio[1138]: info: MPD Permissions set May 02 23:57:15 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:15 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:15 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:15 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:15 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:15 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:15 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:15 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:15 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:15 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:15 volumior volumio[1138]: info: Starting Shairport Sync May 02 23:57:15 volumior volumio[1138]: info: Asound.conf file unchanged, so no further update is needed May 02 23:57:15 volumior volumio[1138]: info: Output device has changed, restarting MPD May 02 23:57:15 volumior sudo[1528]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 02 23:57:15 volumior sudo[1528]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:15 volumior volumio[1138]: info: Output device has changed, restarting Shairport Sync May 02 23:57:15 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:15 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:15 volumior go-librespot[1412]: time="2025-05-02T23:57:15+02:00" level=info msg="authenticated Login5 as 31xfvtnrbmt6ansibhk5tw7q544i" May 02 23:57:15 volumior go-librespot[1412]: time="2025-05-02T23:57:15+02:00" level=debug msg="initializing zeroconf session, username: 31xfvtnrbmt6ansibhk5tw7q544i" May 02 23:57:15 volumior sudo[1533]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 02 23:57:15 volumior sudo[1531]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 02 23:57:15 volumior sudo[1531]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:15 volumior sudo[1533]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:15 volumior sudo[1531]: pam_unix(sudo:session): session closed for user root May 02 23:57:15 volumior volumio[1138]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 02 23:57:15 volumior volumio[1138]: info: MPD Permissions set May 02 23:57:15 volumior systemd[1]: ifup@eth0.service: Current command vanished from the unit file, execution of the command list won't be resumed. May 02 23:57:15 volumior volumio[1138]: SPOTIFY: User informations: {"country":"ES","display_name":"Ricky","email":"martinh.ricardo@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31xfvtnrbmt6ansibhk5tw7q544i"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31xfvtnrbmt6ansibhk5tw7q544i","id":"31xfvtnrbmt6ansibhk5tw7q544i","images":[],"product":"free","type":"user","uri":"spotify:user:31xfvtnrbmt6ansibhk5tw7q544i"} May 02 23:57:15 volumior volumio[1138]: info: Spotify Successfully logged in May 02 23:57:15 volumior volumio[1138]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 02 23:57:15 volumior volumio[1138]: info: [1746223035233] CoreMusicLibrary::Adding element Spotify May 02 23:57:15 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 02 23:57:15 volumior volumio[1138]: Cannot find translation for source Spotify May 02 23:57:15 volumior go-librespot[1412]: time="2025-05-02T23:57:15+02:00" level=debug msg="dealer connection opened" May 02 23:57:15 volumior go-librespot[1412]: time="2025-05-02T23:57:15+02:00" level=trace msg="starting accesspoint recv loop" May 02 23:57:15 volumior go-librespot[1412]: time="2025-05-02T23:57:15+02:00" level=trace msg="starting dealer recv loop" May 02 23:57:15 volumior go-librespot[1412]: time="2025-05-02T23:57:15+02:00" level=trace msg="received accesspoint ping" May 02 23:57:15 volumior go-librespot[1412]: time="2025-05-02T23:57:15+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 02 23:57:15 volumior go-librespot[1412]: time="2025-05-02T23:57:15+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 02 23:57:15 volumior go-librespot[1412]: time="2025-05-02T23:57:15+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 02 23:57:15 volumior go-librespot[1412]: time="2025-05-02T23:57:15+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 02 23:57:15 volumior go-librespot[1412]: time="2025-05-02T23:57:15+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" May 02 23:57:15 volumior go-librespot[1412]: time="2025-05-02T23:57:15+02:00" level=debug msg="received connection id: N2Q3ZDBlMGEtYTEwOC00MDgxLTg5YmEtY2Q2MWM1ZmJlZjNhK2RlYWxlcit0Y3A6Ly8wYWNhNDBiMy5pcC5nZXcxLnNwb3RpZnkubmV0OjU3MDArRkRBMzlENTI4ODBBNkQzQjQxMUZCNzBDRDc3OEUzRENFNDM2NjMyRTE1MkI2QjY0MjAxMTNBMTQwNjA0QjkwMg==" May 02 23:57:15 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:15 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:15 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:15 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:15 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:15 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:15 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:15 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:15 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:15 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:15 volumior go-librespot[1412]: time="2025-05-02T23:57:15+02:00" level=trace msg="received accesspoint pong ack" May 02 23:57:15 volumior volumio[1138]: info: camilladsp service started and running in background, instance 1 May 02 23:57:15 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:15 volumior volumio[1138]: info: FusionDsp - AAAAAAAAAAAAAA-> 44100 48000 88200 96000 176400 192000 384000 <-AAAAAAAAAAAAA May 02 23:57:15 volumior go-librespot[1412]: time="2025-05-02T23:57:15+02:00" level=debug msg="put connect state because NEW_DEVICE" May 02 23:57:15 volumior volumio[1138]: info: FusionDsp loaded May 02 23:57:15 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 02 23:57:15 volumior volumio[1138]: info: FusionDsp - Reporting Fusion DSP Enabled May 02 23:57:15 volumior volumio[1138]: info: Adding Signal Path Element [object Object] May 02 23:57:15 volumior volumio[1138]: info: Adding fusiondspeq DSP Signal Path Element May 02 23:57:15 volumior sudo[1556]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service May 02 23:57:15 volumior sudo[1434]: pam_unix(sudo:session): session closed for user root May 02 23:57:15 volumior sudo[1556]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:15 volumior volumio[1138]: info: FusionDsp - ---- installed callbackRead May 02 23:57:15 volumior volumio[1138]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 02 23:57:15 volumior volumio[1138]: info: succeeded May 02 23:57:15 volumior volumio[1138]: error: FusionDsp - WebSocket error: [object Object] May 02 23:57:15 volumior volumio[1138]: info: Starting Shairport Sync May 02 23:57:15 volumior systemd[1]: Started FusionDsp Daemon. May 02 23:57:15 volumior systemd[1]: musicservicesshield.service: Succeeded. May 02 23:57:15 volumior systemd[1]: Stopped Shield Volumio Music Services in the User CPU Set. May 02 23:57:15 volumior systemd[1]: Stopping Shield Volumio Music Services in the User CPU Set... May 02 23:57:15 volumior systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 02 23:57:15 volumior systemd[1]: shairport-sync.service: Succeeded. May 02 23:57:15 volumior systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 02 23:57:15 volumior systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM May 02 23:57:15 volumior systemd[1]: mpd.service: Succeeded. May 02 23:57:15 volumior systemd[1]: Stopped Music Player Daemon. May 02 23:57:15 volumior volumio[1138]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 May 02 23:57:15 volumior sudo[1556]: pam_unix(sudo:session): session closed for user root May 02 23:57:15 volumior systemd[1]: Starting Music Player Daemon... May 02 23:57:15 volumior systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 02 23:57:15 volumior sudo[1563]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 02 23:57:15 volumior sudo[1528]: pam_unix(sudo:session): session closed for user root May 02 23:57:15 volumior sudo[1509]: pam_unix(sudo:session): session closed for user root May 02 23:57:15 volumior sudo[1563]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:15 volumior volumio[1138]: info: Shairport-Sync Started May 02 23:57:15 volumior volumio[1138]: info: Shairport-Sync Started May 02 23:57:15 volumior systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 02 23:57:15 volumior systemd[1]: shairport-sync.service: Succeeded. May 02 23:57:15 volumior systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 02 23:57:15 volumior systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 02 23:57:15 volumior sudo[1563]: pam_unix(sudo:session): session closed for user root May 02 23:57:15 volumior sudo[1564]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 02 23:57:15 volumior volumio[1138]: info: Shairport-Sync Started May 02 23:57:15 volumior sudo[1564]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:15 volumior sudo[1564]: pam_unix(sudo:session): session closed for user root May 02 23:57:15 volumior systemd[1]: systemd-fsckd.service: Succeeded. May 02 23:57:16 volumior mpd[1571]: May 02 23:57 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 02 23:57:16 volumior systemd[1]: Started Music Player Daemon. May 02 23:57:16 volumior sudo[1477]: pam_unix(sudo:session): session closed for user root May 02 23:57:16 volumior sudo[1533]: pam_unix(sudo:session): session closed for user root May 02 23:57:16 volumior sudo[1514]: pam_unix(sudo:session): session closed for user root May 02 23:57:16 volumior volumio[1138]: error: MPD error: The expression evaluated to a falsy value: May 02 23:57:16 volumior volumio[1138]: assert.ok(self.idling) May 02 23:57:16 volumior volumio[1138]: error: The expression evaluated to a falsy value: May 02 23:57:16 volumior volumio[1138]: assert.ok(self.idling) May 02 23:57:16 volumior volumio[1138]: error: MPD error: The expression evaluated to a falsy value: May 02 23:57:16 volumior volumio[1138]: assert.ok(self.idling) May 02 23:57:16 volumior volumio[1138]: error: The expression evaluated to a falsy value: May 02 23:57:16 volumior volumio[1138]: assert.ok(self.idling) May 02 23:57:16 volumior volumio[1138]: error: updateQueue error: null May 02 23:57:16 volumior systemd[1]: Starting Shield Volumio Music Services in the User CPU Set... May 02 23:57:16 volumior volumio[1138]: 0+0 records in May 02 23:57:16 volumior volumio[1138]: 0+0 records out May 02 23:57:16 volumior volumio[1138]: 0 bytes copied, 0.0008259 s, 0.0 kB/s May 02 23:57:16 volumior volumio[1138]: verbose: New Socket.io Connection to 192.168.0.123 from 192.168.0.114 UA: Mozilla/5.0 (Linux; Android 14; SM-G998B Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.60 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 May 02 23:57:16 volumior volumio[1138]: info: CoreCommandRouter::volumioGetState May 02 23:57:16 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:57:16 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 02 23:57:16 volumior volumio[1138]: info: Listing playlists May 02 23:57:16 volumior volumio[1138]: info: CoreCommandRouter::volumioGetVisibleSources May 02 23:57:16 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 02 23:57:16 volumior volumio[1138]: info: CoreCommandRouter::volumioGetQueue May 02 23:57:16 volumior volumio[1138]: info: CoreStateMachine::getQueue May 02 23:57:16 volumior volumio[1138]: info: CorePlayQueue::getQueue May 02 23:57:16 volumior sh[630]: timed out May 02 23:57:16 volumior dhcpcd[680]: timed out May 02 23:57:16 volumior sh[630]: dhcpcd exited May 02 23:57:16 volumior dhcpcd[680]: dhcpcd exited May 02 23:57:16 volumior sh[630]: ifup: failed to bring up eth0 May 02 23:57:16 volumior systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE May 02 23:57:16 volumior systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. May 02 23:57:16 volumior volumio[1576]: cset: --> shielding system active with May 02 23:57:16 volumior volumio[1576]: cset: "system" cpuset of CPUSPEC(1-3) with 107 tasks running May 02 23:57:16 volumior volumio[1576]: cset: "user" cpuset of CPUSPEC(0) with 3 tasks running May 02 23:57:16 volumior systemd[1]: Started Shield Volumio Music Services in the User CPU Set. May 02 23:57:17 volumior volumio[1138]: info: go-librespot daemon successfully initialized May 02 23:57:17 volumior volumio[1138]: 0+0 records in May 02 23:57:17 volumior volumio[1138]: 0+0 records out May 02 23:57:17 volumior volumio[1138]: 0 bytes copied, 9.7777e-05 s, 0.0 kB/s May 02 23:57:17 volumior sudo[1603]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.0.101/Multimedia/Musica/Wav /mnt/NAS/NAS May 02 23:57:17 volumior sudo[1603]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:17 volumior kernel: CIFS: Attempting to mount //192.168.0.101/Multimedia/Musica/Wav May 02 23:57:17 volumior kernel: CIFS: VFS: \\192.168.0.101 failed to connect to IPC (rc=-13) May 02 23:57:17 volumior kernel: CIFS: VFS: session 3195cb52 has no tcon available for a dfs referral request May 02 23:57:17 volumior sudo[1603]: pam_unix(sudo:session): session closed for user root May 02 23:57:17 volumior volumio[1138]: info: Cannot mount NAS NAS at system boot, trial number 2 ,retrying in 5 seconds May 02 23:57:17 volumior kernel: CIFS: VFS: cifs_mount failed w/return code = -13 May 02 23:57:18 volumior systemd[1]: systemd-hostnamed.service: Succeeded. May 02 23:57:18 volumior sudo[1625]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 02 23:57:18 volumior sudo[1625]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:18 volumior sudo[1625]: pam_unix(sudo:session): session closed for user root May 02 23:57:18 volumior sudo[1627]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 02 23:57:18 volumior sudo[1627]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:18 volumior sudo[1627]: pam_unix(sudo:session): session closed for user root May 02 23:57:18 volumior sudo[1631]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 02 23:57:18 volumior sudo[1631]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:18 volumior systemd[1]: Started UPnP Renderer front-end to MPD. May 02 23:57:18 volumior sudo[1631]: pam_unix(sudo:session): session closed for user root May 02 23:57:18 volumior volumio[1138]: info: Upmpdcli Daemon Started May 02 23:57:18 volumior volumio[1633]: Generating RSA private key, 4096 bit long modulus (2 primes) May 02 23:57:18 volumior volumio[1138]: 0+0 records in May 02 23:57:18 volumior volumio[1138]: 0+0 records out May 02 23:57:18 volumior volumio[1138]: 0 bytes copied, 0.000107184 s, 0.0 kB/s May 02 23:57:18 volumior volumio[1633]: ...++++ May 02 23:57:19 volumior volumio[1633]: .++++ May 02 23:57:19 volumior volumio[1633]: e is 65537 (0x010001) May 02 23:57:19 volumior volumio[1633]: writing RSA key May 02 23:57:19 volumior volumio[1138]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory May 02 23:57:19 volumior volumio[1138]: 0+0 records in May 02 23:57:19 volumior volumio[1138]: 0+0 records out May 02 23:57:19 volumior volumio[1138]: 0 bytes copied, 9.7147e-05 s, 0.0 kB/s May 02 23:57:20 volumior volumio[1138]: info: Initializing connection to go-librespot Websocket May 02 23:57:20 volumior go-librespot[1412]: time="2025-05-02T23:57:20+02:00" level=debug msg="new websocket client" May 02 23:57:20 volumior volumio[1138]: info: Connection to go-librespot Websocket established May 02 23:57:20 volumior volumio[1138]: 0+0 records in May 02 23:57:20 volumior volumio[1138]: 0+0 records out May 02 23:57:20 volumior volumio[1138]: 0 bytes copied, 9.9536e-05 s, 0.0 kB/s May 02 23:57:21 volumior volumio[1138]: 0+0 records in May 02 23:57:21 volumior volumio[1138]: 0+0 records out May 02 23:57:21 volumior volumio[1138]: 0 bytes copied, 9.8573e-05 s, 0.0 kB/s May 02 23:57:22 volumior volumio[1138]: 0+0 records in May 02 23:57:22 volumior volumio[1138]: 0+0 records out May 02 23:57:22 volumior volumio[1138]: 0 bytes copied, 0.000112018 s, 0.0 kB/s May 02 23:57:22 volumior sudo[1691]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 02 23:57:22 volumior sudo[1691]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:22 volumior sudo[1691]: pam_unix(sudo:session): session closed for user root May 02 23:57:23 volumior sudo[1693]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 02 23:57:23 volumior sudo[1693]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:23 volumior sudo[1693]: pam_unix(sudo:session): session closed for user root May 02 23:57:23 volumior sudo[1696]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.0.101/Multimedia/Musica/Wav /mnt/NAS/NAS May 02 23:57:23 volumior sudo[1696]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:23 volumior kernel: CIFS: Attempting to mount //192.168.0.101/Multimedia/Musica/Wav May 02 23:57:23 volumior volumio[1138]: verbose: New Socket.io Connection to 192.168.0.123 from 192.168.0.114 UA: Mozilla/5.0 (Linux; Android 14; SM-G998B Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.60 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 12 May 02 23:57:23 volumior kernel: CIFS: VFS: \\192.168.0.101 failed to connect to IPC (rc=-13) May 02 23:57:23 volumior kernel: CIFS: VFS: session aa9924ec has no tcon available for a dfs referral request May 02 23:57:23 volumior kernel: CIFS: VFS: cifs_mount failed w/return code = -13 May 02 23:57:23 volumior sudo[1696]: pam_unix(sudo:session): session closed for user root May 02 23:57:23 volumior volumio[1138]: info: Cannot mount NAS NAS at system boot, trial number 3 ,retrying in 5 seconds May 02 23:57:23 volumior volumio[1138]: info: Getting Spotify volume May 02 23:57:23 volumior volumio[1138]: info: Spotify volume: 100 May 02 23:57:23 volumior volumio[1138]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 May 02 23:57:23 volumior volumio[1138]: info: CoreCommandRouter::volumioGetState May 02 23:57:23 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:57:23 volumior volumio[1138]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 May 02 23:57:23 volumior volumio[1138]: SPOTIFY: SPOTIFY VOLUME 100 May 02 23:57:23 volumior volumio[1138]: SPOTIFY: VOLUMIO VOLUME 50 May 02 23:57:23 volumior volumio[1138]: SPOTIFY: DELTA VOLUME ENOUGH: true May 02 23:57:23 volumior volumio[1138]: info: Setting Spotify Volume from Volumio: 50 May 02 23:57:23 volumior volumio[1138]: info: CoreCommandRouter::volumioGetState May 02 23:57:23 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:57:23 volumior volumio[1138]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium May 02 23:57:23 volumior volumio[1138]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium May 02 23:57:23 volumior volumio[1138]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium May 02 23:57:23 volumior volumio[1138]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium May 02 23:57:23 volumior volumio[1138]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium May 02 23:57:23 volumior volumio[1138]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium May 02 23:57:23 volumior volumio[1138]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium May 02 23:57:23 volumior volumio[1138]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium May 02 23:57:23 volumior volumio[1138]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium May 02 23:57:23 volumior volumio[1138]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium May 02 23:57:23 volumior volumio[1138]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium May 02 23:57:23 volumior volumio[1138]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar May 02 23:57:23 volumior volumio[1138]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar May 02 23:57:23 volumior volumio[1138]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar May 02 23:57:23 volumior volumio[1138]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar May 02 23:57:23 volumior volumio[1138]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar May 02 23:57:23 volumior volumio[1138]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar May 02 23:57:23 volumior volumio[1138]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar May 02 23:57:23 volumior volumio[1138]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar May 02 23:57:23 volumior volumio[1138]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar May 02 23:57:23 volumior volumio[1138]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar May 02 23:57:23 volumior volumio[1138]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso May 02 23:57:23 volumior volumio[1138]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso May 02 23:57:23 volumior volumio[1138]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso May 02 23:57:23 volumior volumio[1138]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso May 02 23:57:23 volumior volumio[1138]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso May 02 23:57:23 volumior volumio[1138]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso May 02 23:57:23 volumior volumio[1138]: info: Adding plugin bluetooth to MyMusic Plugins May 02 23:57:23 volumior volumio[1138]: info: Adding plugin multiroom to MyMusic Plugins May 02 23:57:23 volumior volumio[1138]: info: Adding plugin metavolumio to MyMusic Plugins May 02 23:57:23 volumior volumio[1138]: info: Adding plugin cd_controller to MyMusic Plugins May 02 23:57:23 volumior volumio[1138]: info: Adding plugin smart_inputs to MyMusic Plugins May 02 23:57:23 volumior volumio[1138]: info: Adding plugin tidalconnect to MyMusic Plugins May 02 23:57:23 volumior volumio[1138]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... May 02 23:57:24 volumior volumio[1138]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded May 02 23:57:24 volumior volumio[1138]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio May 02 23:57:24 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:24 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:24 volumior volumio[1138]: info: Starting MyVolumio Remote Streaming Endpoints May 02 23:57:24 volumior volumio[1138]: info: MyVolumio login type: Token May 02 23:57:24 volumior volumio[1138]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started May 02 23:57:24 volumior volumio[1138]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... May 02 23:57:24 volumior volumio[1138]: info: Starting Streaming Service Transparent Proxy May 02 23:57:24 volumior volumio[1138]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded May 02 23:57:24 volumior volumio[1138]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services May 02 23:57:24 volumior volumio[1138]: info: Streaming services startup May 02 23:57:24 volumior volumio[1138]: info: Starting Streaming Daemon May 02 23:57:24 volumior sudo[1709]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 02 23:57:24 volumior sudo[1709]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:24 volumior sudo[1709]: pam_unix(sudo:session): session closed for user root May 02 23:57:24 volumior volumio[1138]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started May 02 23:57:25 volumior volumio[1138]: 0+0 records in May 02 23:57:25 volumior volumio[1138]: 0+0 records out May 02 23:57:25 volumior volumio[1138]: 0 bytes copied, 0.000160968 s, 0.0 kB/s May 02 23:57:25 volumior volumio[1138]: SPOTIFY: SETTING SPOTIFY VOLUME 50 May 02 23:57:25 volumior volumio[1138]: info: Sending Spotify command with payload to local API: /player/volume May 02 23:57:25 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 02 23:57:25 volumior volumio[1138]: info: Listing playlists May 02 23:57:25 volumior volumio[1138]: info: CoreCommandRouter::volumioGetVisibleSources May 02 23:57:25 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 02 23:57:25 volumior volumio[1138]: info: CoreCommandRouter::volumioGetQueue May 02 23:57:25 volumior volumio[1138]: info: CoreStateMachine::getQueue May 02 23:57:25 volumior volumio[1138]: info: CorePlayQueue::getQueue May 02 23:57:25 volumior volumio[1138]: error: Cannot start Volumio Streaming Daemon May 02 23:57:25 volumior volumio[1138]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 02 23:57:25 volumior volumio[1138]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 02 23:57:25 volumior go-librespot[1412]: time="2025-05-02T23:57:25+02:00" level=debug msg="update volume to 32767/65535" May 02 23:57:25 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 02 23:57:25 volumior volumio[1138]: info: Received Get System Info May 02 23:57:25 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 02 23:57:25 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 02 23:57:25 volumior volumio[1138]: info: Discovery: Getting this device information May 02 23:57:25 volumior volumio[1138]: info: CoreCommandRouter::volumioGetState May 02 23:57:25 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:57:25 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 02 23:57:25 volumior volumio[1138]: STREAMING PROXY: Starting server on port 3245 May 02 23:57:25 volumior volumio[1138]: Node JS runtime: 14 May 02 23:57:25 volumior volumio[1138]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN May 02 23:57:25 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken May 02 23:57:25 volumior volumio[1138]: info: MyVolumio login type: Token May 02 23:57:25 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 02 23:57:25 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 02 23:57:25 volumior volumio[1138]: info: Discovery: Getting this device information May 02 23:57:25 volumior volumio[1138]: info: CoreCommandRouter::volumioGetState May 02 23:57:25 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:57:25 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 02 23:57:25 volumior volumio[1138]: verbose: New Socket.io Connection to 192.168.0.123:3000 from 192.168.0.114 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 13 May 02 23:57:25 volumior volumio[1138]: info: CoreCommandRouter::volumioGetState May 02 23:57:25 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:57:25 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 02 23:57:26 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 02 23:57:26 volumior volumio[1138]: 0+0 records in May 02 23:57:26 volumior volumio[1138]: 0+0 records out May 02 23:57:26 volumior volumio[1138]: 0 bytes copied, 9.8085e-05 s, 0.0 kB/s May 02 23:57:26 volumior go-librespot[1412]: time="2025-05-02T23:57:26+02:00" level=debug msg="put connect state because VOLUME_CHANGED" May 02 23:57:26 volumior go-librespot[1412]: time="2025-05-02T23:57:26+02:00" level=trace msg="emitting websocket event: volume" May 02 23:57:26 volumior volumio[1138]: SPOTIFY: received: {"type":"volume","data":{"value":50,"max":100}} May 02 23:57:26 volumior volumio[1138]: SPOTIFY: RECEIVED SPOTIFY VOLUME 50 May 02 23:57:26 volumior volumio[1138]: info: MyVolumio token set successfully May 02 23:57:26 volumior volumio[1138]: info: MYVOLUMIO: Adding device May 02 23:57:26 volumior volumio[1138]: info: MYVOLUMIO: Evaluating Server May 02 23:57:26 volumior volumio[1138]: info: MyVolumio Plan changed: premium May 02 23:57:26 volumior volumio[1138]: info: [MyVolumio PluginManager] Subscribed plan changed to premium May 02 23:57:26 volumior volumio[1138]: info: Removing browser output: myVolumio user plan is not superstar May 02 23:57:26 volumior volumio[1138]: info: Removing audio output: May 02 23:57:26 volumior volumio[1138]: info: MYVOLUMIO: Adding device May 02 23:57:26 volumior volumio[1138]: info: MYVOLUMIO: Evaluating Server May 02 23:57:26 volumior volumio[1138]: info: Remote config written successfully May 02 23:57:26 volumior volumio[1138]: info: Starting Tunnel 1 May 02 23:57:26 volumior volumio[1138]: info: Starting Tunnel Connection Checker May 02 23:57:26 volumior volumio[1138]: info: Completed starting MyVolumio Plugin May 02 23:57:26 volumior volumio[1138]: info: MYVolumio Device enabled May 02 23:57:26 volumior volumio[1138]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... May 02 23:57:26 volumior volumio[1138]: info: MyVolumio status changed May 02 23:57:26 volumior volumio[1138]: info: Streaming services startup May 02 23:57:26 volumior volumio[1138]: info: Starting Streaming Daemon May 02 23:57:27 volumior volumio[1138]: info: Setting Geolocation for MyVolumio to eu4 May 02 23:57:27 volumior sudo[1759]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 02 23:57:27 volumior sudo[1759]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:27 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:27 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:27 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:27 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid May 02 23:57:27 volumior sudo[1759]: pam_unix(sudo:session): session closed for user root May 02 23:57:27 volumior volumio[1138]: info: [MyVolumio PluginManager] Plugin music_service/qobuzconnect is enabled for this plan, but could not be found on the local filesystem! May 02 23:57:27 volumior volumio[1138]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... May 02 23:57:27 volumior volumio[1138]: info: [1746223047159] Starting BluetoothController May 02 23:57:27 volumior volumio[1138]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... May 02 23:57:28 volumior volumio[1138]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom May 02 23:57:28 volumior sudo[1776]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom May 02 23:57:28 volumior sudo[1776]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:28 volumior sudo[1776]: pam_unix(sudo:session): session closed for user root May 02 23:57:28 volumior volumio[1138]: info: MRS: MultiRoom plugin initialized May 02 23:57:28 volumior volumio[1138]: info: MRS: STOPPING SNAPCLIENT May 02 23:57:28 volumior volumio[1138]: info: MRS: Snap server stop May 02 23:57:28 volumior sudo[1792]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient May 02 23:57:28 volumior sudo[1792]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:28 volumior volumio[1138]: info: MRS: STOPPING volumioStreaming May 02 23:57:28 volumior sudo[1795]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver May 02 23:57:28 volumior sudo[1795]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:28 volumior sudo[1792]: pam_unix(sudo:session): session closed for user root May 02 23:57:28 volumior volumio[1138]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... May 02 23:57:28 volumior sudo[1795]: pam_unix(sudo:session): session closed for user root May 02 23:57:28 volumior sudo[1798]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming May 02 23:57:28 volumior sudo[1798]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:28 volumior sudo[1800]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* May 02 23:57:28 volumior sudo[1800]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:28 volumior volumio[1138]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... May 02 23:57:28 volumior sudo[1800]: pam_unix(sudo:session): session closed for user root May 02 23:57:28 volumior volumio[1138]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... May 02 23:57:28 volumior sudo[1798]: pam_unix(sudo:session): session closed for user root May 02 23:57:28 volumior volumio[1138]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... May 02 23:57:28 volumior volumio[1138]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... May 02 23:57:28 volumior volumio[1138]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio May 02 23:57:28 volumior volumio[1138]: info: [MyVolumio PluginManager] Loading plugin "tidal"... May 02 23:57:28 volumior volumio[1138]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... May 02 23:57:28 volumior volumio[1138]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... May 02 23:57:28 volumior volumio[1138]: info: Preparing to generate the ALSA configuration file May 02 23:57:28 volumior volumio[1138]: 0+0 records in May 02 23:57:28 volumior volumio[1138]: 0+0 records out May 02 23:57:28 volumior volumio[1138]: 0 bytes copied, 0.000115354 s, 0.0 kB/s May 02 23:57:28 volumior volumio[1138]: info: Updating MyVolumio device info May 02 23:57:28 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:28 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:28 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:28 volumior volumio[1138]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 02 23:57:28 volumior volumio[1138]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 02 23:57:28 volumior volumio[1138]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf May 02 23:57:28 volumior volumio[1138]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf May 02 23:57:28 volumior volumio[1138]: info: Reading ALSA contributions from plugins. May 02 23:57:28 volumior sudo[1809]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.0.101/Multimedia/Musica/Wav /mnt/NAS/NAS May 02 23:57:28 volumior sudo[1809]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:28 volumior volumio[1138]: info: Setting Geolocation for MyVolumio to eu6 May 02 23:57:28 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:28 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:28 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:28 volumior kernel: CIFS: Attempting to mount //192.168.0.101/Multimedia/Musica/Wav May 02 23:57:28 volumior volumio[1138]: info: MRS: Removed streaming files May 02 23:57:28 volumior volumio[1138]: info: MRS: volumioStreaming STOPPED May 02 23:57:28 volumior volumio[1138]: info: MRS: SNAPSERVER STOPPED May 02 23:57:28 volumior volumio[1138]: info: MRS: SNAPCLIENT STOPPED May 02 23:57:28 volumior volumio[1138]: error: Cannot start Volumio Streaming Daemon May 02 23:57:28 volumior volumio[1138]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 02 23:57:28 volumior volumio[1138]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 02 23:57:28 volumior volumio[1138]: info: Asound.conf file written May 02 23:57:28 volumior sudo[1815]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf May 02 23:57:28 volumior sudo[1815]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:28 volumior sudo[1815]: pam_unix(sudo:session): session closed for user root May 02 23:57:28 volumior sudo[1809]: pam_unix(sudo:session): session closed for user root May 02 23:57:28 volumior kernel: CIFS: VFS: \\192.168.0.101 failed to connect to IPC (rc=-13) May 02 23:57:28 volumior kernel: CIFS: VFS: session aaacb604 has no tcon available for a dfs referral request May 02 23:57:28 volumior kernel: CIFS: VFS: cifs_mount failed w/return code = -13 May 02 23:57:28 volumior volumio[1138]: info: Output device has changed, restarting MPD May 02 23:57:28 volumior sudo[1820]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 02 23:57:28 volumior sudo[1820]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:28 volumior volumio[1138]: info: Output device has changed, restarting Shairport Sync May 02 23:57:28 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:28 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:28 volumior sudo[1820]: pam_unix(sudo:session): session closed for user root May 02 23:57:28 volumior sudo[1823]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 02 23:57:28 volumior sudo[1823]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:28 volumior systemd[1]: musicservicesshield.service: Succeeded. May 02 23:57:28 volumior systemd[1]: Stopped Shield Volumio Music Services in the User CPU Set. May 02 23:57:28 volumior systemd[1]: Stopping Shield Volumio Music Services in the User CPU Set... May 02 23:57:28 volumior systemd[1]: Stopping Music Player Daemon... May 02 23:57:28 volumior volumio[1138]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 02 23:57:28 volumior volumio[1138]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 02 23:57:28 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:28 volumior systemd[1]: mpd.service: Succeeded. May 02 23:57:28 volumior systemd[1]: Stopped Music Player Daemon. May 02 23:57:28 volumior volumio[1138]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth May 02 23:57:28 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 02 23:57:28 volumior systemd[1]: Starting Music Player Daemon... May 02 23:57:28 volumior volumio[1138]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom May 02 23:57:28 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus May 02 23:57:28 volumior volumio[1138]: info: MRS: Pushing multiroomSync output for this device May 02 23:57:28 volumior volumio[1138]: info: MRS: Pushing multiroomSync output May 02 23:57:28 volumior volumio[1138]: info: Adding audio output: May 02 23:57:28 volumior volumio[1138]: info: Adding audio output: May 02 23:57:28 volumior sudo[1832]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name Volumior May 02 23:57:28 volumior sudo[1832]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:28 volumior volumio[1138]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 02 23:57:28 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:28 volumior sudo[1832]: pam_unix(sudo:session): session closed for user root May 02 23:57:28 volumior volumio[1138]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio May 02 23:57:28 volumior volumio[1138]: info: Adding METAVOLUMIO REST API Endpoints May 02 23:57:28 volumior volumio[1138]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio May 02 23:57:28 volumior volumio[1138]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio May 02 23:57:28 volumior volumio[1138]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio May 02 23:57:28 volumior volumio[1138]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio May 02 23:57:28 volumior volumio[1138]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui May 02 23:57:28 volumior volumio[1138]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller May 02 23:57:28 volumior volumio[1138]: info: Preparing CD Folders May 02 23:57:28 volumior volumio[1138]: info: Adding CD REST API Endpoints May 02 23:57:28 volumior volumio[1138]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller May 02 23:57:28 volumior volumio[1138]: info: Starting UDEV Watcher for CD May 02 23:57:28 volumior volumio[1138]: info: Detecting CD presence with UDEV May 02 23:57:28 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices May 02 23:57:29 volumior sudo[1829]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 02 23:57:29 volumior sudo[1829]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:29 volumior sudo[1829]: pam_unix(sudo:session): session closed for user root May 02 23:57:29 volumior volumio[1138]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs May 02 23:57:29 volumior volumio[1138]: info: Adding inputs REST Endpoints May 02 23:57:29 volumior volumio[1138]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs May 02 23:57:29 volumior volumio[1138]: info: Scanning Audio Inputs May 02 23:57:29 volumior volumio[1138]: info: Checking against Known Cards name May 02 23:57:29 volumior volumio[1138]: info: Adding Server instance for streaming May 02 23:57:29 volumior volumio[1138]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio May 02 23:57:29 volumior volumio[1138]: error: Hi Res Audio Failed Login: Missing Login Data May 02 23:57:29 volumior volumio[1138]: info: Adding HIGHRESAUDIO REST API Endpoints May 02 23:57:29 volumior volumio[1138]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio May 02 23:57:29 volumior volumio[1138]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal May 02 23:57:29 volumior volumio[1138]: info: Refreshing TIDAL token May 02 23:57:29 volumior volumio[1138]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz May 02 23:57:29 volumior volumio[1138]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect May 02 23:57:29 volumior sudo[1842]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 02 23:57:29 volumior sudo[1842]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:29 volumior volumio[1138]: info: Stopping AccessToken refresher cron for QOBUZ May 02 23:57:29 volumior sudo[1842]: pam_unix(sudo:session): session closed for user root May 02 23:57:29 volumior volumio[1138]: info: AccessToken refresher cron started for QOBUZ May 02 23:57:29 volumior volumio[1138]: info: Adding QOBUZ REST API Endpoints May 02 23:57:29 volumior volumio[1138]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz May 02 23:57:29 volumior volumio[1138]: info: Successfully Added MyVolumio device May 02 23:57:29 volumior volumio[1138]: info: Bluetooth name changed to Volumior May 02 23:57:29 volumior volumio[1138]: info: MPD Permissions set May 02 23:57:29 volumior volumio[1138]: info: Cannot mount NAS NAS at system boot, trial number 4 ,retrying in 5 seconds May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: Starting Shairport Sync May 02 23:57:29 volumior volumio[1138]: info: Preparing to generate the ALSA configuration file May 02 23:57:29 volumior sudo[1851]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 02 23:57:29 volumior sudo[1851]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:29 volumior volumio[1138]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 02 23:57:29 volumior volumio[1138]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf May 02 23:57:29 volumior volumio[1138]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf May 02 23:57:29 volumior volumio[1138]: info: Reading ALSA contributions from plugins. May 02 23:57:29 volumior systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 02 23:57:29 volumior volumio[1138]: info: Asound.conf file written May 02 23:57:29 volumior systemd[1]: shairport-sync.service: Succeeded. May 02 23:57:29 volumior systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 02 23:57:29 volumior sudo[1855]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf May 02 23:57:29 volumior sudo[1855]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:29 volumior systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 02 23:57:29 volumior sudo[1855]: pam_unix(sudo:session): session closed for user root May 02 23:57:29 volumior sudo[1851]: pam_unix(sudo:session): session closed for user root May 02 23:57:29 volumior volumio[1138]: info: Output device has changed, restarting MPD May 02 23:57:29 volumior sudo[1860]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 02 23:57:29 volumior sudo[1860]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:29 volumior sudo[1860]: pam_unix(sudo:session): session closed for user root May 02 23:57:29 volumior volumio[1138]: info: Output device has changed, restarting Shairport Sync May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:29 volumior sudo[1864]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 02 23:57:29 volumior sudo[1864]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:29 volumior volumio[1138]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 02 23:57:29 volumior volumio[1138]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM May 02 23:57:29 volumior systemd[1]: mpd.service: Succeeded. May 02 23:57:29 volumior systemd[1]: Stopped Music Player Daemon. May 02 23:57:29 volumior volumio[1138]: info: Preparing to generate the ALSA configuration file May 02 23:57:29 volumior systemd[1]: Starting Music Player Daemon... May 02 23:57:29 volumior volumio[1138]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 02 23:57:29 volumior volumio[1138]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 02 23:57:29 volumior volumio[1138]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf May 02 23:57:29 volumior volumio[1138]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf May 02 23:57:29 volumior volumio[1138]: info: Reading ALSA contributions from plugins. May 02 23:57:29 volumior volumio[1138]: info: MPD Permissions set May 02 23:57:29 volumior volumio[1138]: info: Shairport-Sync Started May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: Starting Shairport Sync May 02 23:57:29 volumior sudo[1872]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 02 23:57:29 volumior sudo[1872]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:29 volumior sudo[1872]: pam_unix(sudo:session): session closed for user root May 02 23:57:29 volumior volumio[1138]: info: Asound.conf file written May 02 23:57:29 volumior sudo[1880]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 02 23:57:29 volumior sudo[1880]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:29 volumior systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 02 23:57:29 volumior sudo[1883]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf May 02 23:57:29 volumior sudo[1883]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:29 volumior systemd[1]: shairport-sync.service: Succeeded. May 02 23:57:29 volumior systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 02 23:57:29 volumior sudo[1883]: pam_unix(sudo:session): session closed for user root May 02 23:57:29 volumior systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 02 23:57:29 volumior sudo[1880]: pam_unix(sudo:session): session closed for user root May 02 23:57:29 volumior volumio[1138]: info: Output device has changed, restarting MPD May 02 23:57:29 volumior sudo[1891]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 02 23:57:29 volumior sudo[1891]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:29 volumior sudo[1891]: pam_unix(sudo:session): session closed for user root May 02 23:57:29 volumior volumio[1138]: info: Output device has changed, restarting Shairport Sync May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:29 volumior sudo[1894]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 02 23:57:29 volumior sudo[1894]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:29 volumior systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM May 02 23:57:29 volumior systemd[1]: mpd.service: Succeeded. May 02 23:57:29 volumior systemd[1]: Stopped Music Player Daemon. May 02 23:57:29 volumior volumio[1138]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 02 23:57:29 volumior volumio[1138]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: Updating MyVolumio device info May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:29 volumior volumio[1138]: 0+0 records in May 02 23:57:29 volumior volumio[1138]: 0+0 records out May 02 23:57:29 volumior volumio[1138]: 0 bytes copied, 0.000107578 s, 0.0 kB/s May 02 23:57:29 volumior volumio[1138]: info: Successfully Added MyVolumio device May 02 23:57:29 volumior systemd[1]: Starting Music Player Daemon... May 02 23:57:29 volumior volumio[1138]: info: Successfully Updated MyVolumio device May 02 23:57:29 volumior volumio[1138]: info: MPD Permissions set May 02 23:57:29 volumior volumio[1138]: info: Shairport-Sync Started May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:29 volumior volumio[1138]: info: Starting Shairport Sync May 02 23:57:29 volumior sudo[1899]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 02 23:57:29 volumior sudo[1899]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:29 volumior sudo[1899]: pam_unix(sudo:session): session closed for user root May 02 23:57:29 volumior sudo[1914]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 02 23:57:29 volumior sudo[1914]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:29 volumior systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 02 23:57:29 volumior systemd[1]: shairport-sync.service: Succeeded. May 02 23:57:29 volumior systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 02 23:57:29 volumior systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 02 23:57:29 volumior sudo[1914]: pam_unix(sudo:session): session closed for user root May 02 23:57:30 volumior volumio[1138]: info: Shairport-Sync Started May 02 23:57:30 volumior volumio[1138]: info: Access Token successfully retrieved May 02 23:57:30 volumior volumio[1138]: info: Successfully Updated MyVolumio device May 02 23:57:30 volumior volumio[1138]: info: Successfully retrieved User Session From TIDAL May 02 23:57:30 volumior volumio[1138]: info: Successfully retrieved User Subscription From TIDAL May 02 23:57:30 volumior volumio[1138]: info: Adding TIDAL to Browse Sources May 02 23:57:30 volumior volumio[1138]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 02 23:57:30 volumior volumio[1138]: info: [1746223050503] CoreMusicLibrary::Adding element TIDAL May 02 23:57:30 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 02 23:57:30 volumior volumio[1138]: Cannot find translation for source Spotify May 02 23:57:30 volumior volumio[1138]: Cannot find translation for source TIDAL May 02 23:57:30 volumior volumio[1138]: info: Stopping AccessToken refresher cron May 02 23:57:30 volumior volumio[1138]: info: AccessToken refresher cron started May 02 23:57:30 volumior volumio[1138]: info: Adding TIDAL REST API Endpoints May 02 23:57:30 volumior volumio[1138]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal May 02 23:57:30 volumior volumio[1138]: info: MRS: Found cast device: BRAVIA-4K-UR3-e5717e5a36cc412a8dbf6a357e8475d9 May 02 23:57:30 volumior volumio[1138]: info: Adding audio output: May 02 23:57:30 volumior mpd[1913]: May 02 23:57 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 02 23:57:30 volumior systemd[1]: Started Music Player Daemon. May 02 23:57:30 volumior sudo[1894]: pam_unix(sudo:session): session closed for user root May 02 23:57:30 volumior sudo[1864]: pam_unix(sudo:session): session closed for user root May 02 23:57:30 volumior sudo[1823]: pam_unix(sudo:session): session closed for user root May 02 23:57:30 volumior volumio[1138]: error: MPD error: The expression evaluated to a falsy value: May 02 23:57:30 volumior volumio[1138]: assert.ok(self.idling) May 02 23:57:30 volumior volumio[1138]: error: The expression evaluated to a falsy value: May 02 23:57:30 volumior volumio[1138]: assert.ok(self.idling) May 02 23:57:30 volumior volumio[1138]: error: MPD error: The expression evaluated to a falsy value: May 02 23:57:30 volumior volumio[1138]: assert.ok(self.idling) May 02 23:57:30 volumior volumio[1138]: error: The expression evaluated to a falsy value: May 02 23:57:30 volumior volumio[1138]: assert.ok(self.idling) May 02 23:57:30 volumior volumio[1138]: error: updateQueue error: null May 02 23:57:30 volumior systemd[1]: Starting Shield Volumio Music Services in the User CPU Set... May 02 23:57:30 volumior volumio[1138]: 0+0 records in May 02 23:57:30 volumior volumio[1138]: 0+0 records out May 02 23:57:30 volumior volumio[1138]: 0 bytes copied, 0.000107689 s, 0.0 kB/s May 02 23:57:31 volumior volumio[1924]: cset: --> shielding system active with May 02 23:57:31 volumior volumio[1924]: cset: "system" cpuset of CPUSPEC(1-3) with 127 tasks running May 02 23:57:31 volumior volumio[1924]: cset: "user" cpuset of CPUSPEC(0) with 3 tasks running May 02 23:57:31 volumior systemd[1]: Started Shield Volumio Music Services in the User CPU Set. May 02 23:57:31 volumior sudo[1949]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service May 02 23:57:31 volumior sudo[1949]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:31 volumior systemd[1]: Started MyVolumio SSH Tunnel. May 02 23:57:31 volumior sudo[1949]: pam_unix(sudo:session): session closed for user root May 02 23:57:31 volumior volumio[1138]: info: Remote SSH Started May 02 23:57:31 volumior autossh[1952]: port set to 0, monitoring disabled May 02 23:57:31 volumior autossh[1952]: starting ssh (count 1) May 02 23:57:31 volumior autossh[1952]: ssh child pid is 1955 May 02 23:57:31 volumior volumio[1138]: 0+0 records in May 02 23:57:31 volumior volumio[1138]: 0+0 records out May 02 23:57:31 volumior volumio[1138]: 0 bytes copied, 0.000137926 s, 0.0 kB/s May 02 23:57:32 volumior sudo[1962]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service May 02 23:57:32 volumior sudo[1962]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:32 volumior volumiossh-tunnel[1951]: Warning: Permanently added '[eu6.myvolumio.org]:2222,[207.154.233.230]:2222' (RSA) to the list of known hosts. May 02 23:57:32 volumior volumio[1138]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 14 May 02 23:57:32 volumior systemd[1]: Started Volumio Bluetooth Module. May 02 23:57:32 volumior sudo[1962]: pam_unix(sudo:session): session closed for user root May 02 23:57:32 volumior volumio[1138]: info: TidalConnect service stoped! May 02 23:57:32 volumior sudo[1965]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* May 02 23:57:32 volumior sudo[1965]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:32 volumior volumiobt[1964]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory May 02 23:57:32 volumior sudo[1965]: pam_unix(sudo:session): session closed for user root May 02 23:57:32 volumior volumio[1138]: info: CoreCommandRouter::volumioGetState May 02 23:57:32 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:57:32 volumior volumio[1138]: info: Volumio BT Module successfully started May 02 23:57:32 volumior volumio[1138]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 02 23:57:32 volumior volumio[1138]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect May 02 23:57:32 volumior sudo[1977]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 02 23:57:32 volumior sudo[1977]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:32 volumior systemd[1]: Started Volumio Tidal Connect Service. May 02 23:57:32 volumior sudo[1977]: pam_unix(sudo:session): session closed for user root May 02 23:57:32 volumior volumio[1138]: info: Executing endpoint tc_getconfig May 02 23:57:32 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig May 02 23:57:32 volumior vtcs[1979]: STARTING TidalConnect services, version: 1.4.0.34 May 02 23:57:32 volumior vtcs[1979]: STARTED TidalConnect services. May 02 23:57:32 volumior volumio[1138]: info: Executing endpoint tc_connect May 02 23:57:32 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect May 02 23:57:32 volumior volumio[1138]: info: Connecting to TidalConnect May 02 23:57:32 volumior volumio[1138]: info: CoreCommandRouter::servicePushState May 02 23:57:32 volumior volumio[1138]: info: CoreStateMachine::pushState May 02 23:57:32 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:57:32 volumior volumio[1138]: info: CoreCommandRouter::volumioPushState May 02 23:57:32 volumior volumio[1138]: info: MRS: Pushing multiroomSync output update for this device May 02 23:57:32 volumior volumio[1138]: info: MRS: Pushing multiroomSync output May 02 23:57:32 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:57:32 volumior volumio[1138]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received tidalconnect May 02 23:57:32 volumior volumio[1138]: info: CoreCommandRouter::servicePushState May 02 23:57:32 volumior volumio[1138]: info: CoreStateMachine::pushState May 02 23:57:32 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:57:32 volumior volumio[1138]: info: CoreCommandRouter::volumioPushState May 02 23:57:32 volumior volumio[1138]: info: MRS: Pushing multiroomSync output update for this device May 02 23:57:32 volumior volumio[1138]: info: MRS: Pushing multiroomSync output May 02 23:57:32 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:57:32 volumior volumio[1138]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received tidalconnect May 02 23:57:32 volumior volumio[1138]: info: PeppyMeterBasic ---peppymeterbasic status stop May 02 23:57:32 volumior volumio[1138]: info: PeppyMeterBasic ---peppymeterbasic status stop May 02 23:57:32 volumior sudo[1999]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service May 02 23:57:32 volumior sudo[1999]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:32 volumior volumio[1138]: info: PeppySpectrum ---peppyspectrum status stop May 02 23:57:32 volumior sudo[2002]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service May 02 23:57:32 volumior sudo[2002]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:32 volumior sudo[1999]: pam_unix(sudo:session): session closed for user root May 02 23:57:32 volumior volumio[1138]: info: PeppySpectrum ---peppyspectrum status stop May 02 23:57:32 volumior sudo[2005]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service May 02 23:57:32 volumior sudo[2005]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:32 volumior sudo[2008]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service May 02 23:57:32 volumior sudo[2008]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:32 volumior sudo[2002]: pam_unix(sudo:session): session closed for user root May 02 23:57:32 volumior volumio[1138]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 May 02 23:57:32 volumior volumio[1138]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 May 02 23:57:32 volumior sudo[2008]: pam_unix(sudo:session): session closed for user root May 02 23:57:32 volumior sudo[2005]: pam_unix(sudo:session): session closed for user root May 02 23:57:32 volumior volumio[1138]: info: peppyspectrum Daemon Stop May 02 23:57:32 volumior volumio[1138]: info: peppyspectrum Daemon Stop May 02 23:57:32 volumior volumio[1138]: info: peppymeterbasic Daemon Stop May 02 23:57:32 volumior volumio[1138]: info: peppymeterbasic Daemon Stop May 02 23:57:33 volumior volumio[1138]: 0+0 records in May 02 23:57:33 volumior volumio[1138]: 0+0 records out May 02 23:57:33 volumior volumio[1138]: 0 bytes copied, 9.671e-05 s, 0.0 kB/s May 02 23:57:33 volumior sudo[2015]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio May 02 23:57:33 volumior sudo[2015]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:33 volumior volumiobt[1964]: pulseaudio: no process found May 02 23:57:33 volumior sudo[2015]: pam_unix(sudo:session): session closed for user root May 02 23:57:33 volumior dbus-daemon[714]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.26' (uid=1000 pid=2019 comm="/usr/bin/pulseaudio --high-priority=true ") May 02 23:57:33 volumior systemd[1]: Starting RealtimeKit Scheduling Policy Service... May 02 23:57:33 volumior volumio[1138]: ------------------------------------ BT MESSAGE: BT STATUS: running May 02 23:57:33 volumior dbus-daemon[714]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' May 02 23:57:33 volumior systemd[1]: Started RealtimeKit Scheduling Policy Service. May 02 23:57:33 volumior rtkit-daemon[2020]: Successfully called chroot. May 02 23:57:33 volumior rtkit-daemon[2020]: Successfully dropped privileges. May 02 23:57:33 volumior rtkit-daemon[2020]: Successfully limited resources. May 02 23:57:33 volumior rtkit-daemon[2020]: Running. May 02 23:57:33 volumior rtkit-daemon[2020]: Canary thread running. May 02 23:57:33 volumior rtkit-daemon[2020]: Watchdog thread running. May 02 23:57:33 volumior dbus-daemon[714]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.27' (uid=0 pid=2020 comm="/usr/lib/rtkit/rtkit-daemon ") May 02 23:57:33 volumior systemd[1]: Starting Authorization Manager... May 02 23:57:33 volumior volumio[1138]: ------------------------------------ BT MESSAGE: BT STATUS: running May 02 23:57:33 volumior polkitd[2024]: started daemon version 0.105 using authority implementation `local' version `0.105' May 02 23:57:33 volumior dbus-daemon[714]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' May 02 23:57:33 volumior systemd[1]: Started Authorization Manager. May 02 23:57:33 volumior pulseaudio[2019]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 May 02 23:57:33 volumior pulseaudio[2019]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 May 02 23:57:33 volumior volumiobt[1964]: Applying permissions May 02 23:57:33 volumior volumiobt[1964]: Setting BT discoverable and pairable May 02 23:57:33 volumior pulseaudio[2019]: 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 May 02 23:57:33 volumior bluetoothd[867]: Endpoint registered: sender=:1.47 path=/MediaEndpoint/A2DPSource May 02 23:57:33 volumior bluetoothd[867]: Endpoint registered: sender=:1.47 path=/MediaEndpoint/A2DPSink May 02 23:57:33 volumior kernel: Bluetooth: RFCOMM TTY layer initialized May 02 23:57:33 volumior kernel: Bluetooth: RFCOMM socket layer initialized May 02 23:57:33 volumior kernel: Bluetooth: RFCOMM ver 1.11 May 02 23:57:33 volumior volumiobt[1964]: [CHG] Controller D8:3A:DD:FC:A8:DE UUIDs: 00001112-0000-1000-8000-00805f9b34fb May 02 23:57:33 volumior volumiobt[1964]: [117B blob data] May 02 23:57:33 volumior volumiobt[1964]: [117B blob data] May 02 23:57:33 volumior volumiobt[1964]: [117B blob data] May 02 23:57:33 volumior volumiobt[1964]: [117B blob data] May 02 23:57:33 volumior volumiobt[1964]: [117B blob data] May 02 23:57:33 volumior volumiobt[1964]: [117B blob data] May 02 23:57:33 volumior volumiobt[1964]: [117B blob data] May 02 23:57:33 volumior volumiobt[1964]: [117B blob data] May 02 23:57:33 volumior volumiobt[1964]: [55B blob data] May 02 23:57:33 volumior volumiobt[1964]: [bluetooth]# -e power on May 02 23:57:33 volumior volumiobt[1964]: Invalid command in menu main: -e May 02 23:57:33 volumior volumiobt[1964]: May 02 23:57:33 volumior volumiobt[1964]: Use "help" for a list of available commands in a menu. May 02 23:57:33 volumior volumiobt[1964]: Use "menu " if you want to enter any submenu. May 02 23:57:33 volumior volumiobt[1964]: Use "back" if you want to return to menu main. May 02 23:57:33 volumior volumiobt[1964]: [bluetooth]# agent on May 02 23:57:33 volumior volumiobt[1964]: Agent is already registered May 02 23:57:33 volumior volumiobt[1964]: [bluetooth]# discoverable on May 02 23:57:33 volumior volumiobt[1964]: [bluetooth]# pairable on May 02 23:57:33 volumior volumiobt[1964]: [bluetooth]# agent NoInputNoOutput May 02 23:57:33 volumior volumiobt[1964]: Agent is already registered May 02 23:57:33 volumior volumiobt[1964]: [bluetooth]# default-agent May 02 23:57:33 volumior volumiobt[1964]: [bluetooth]# quit May 02 23:57:33 volumior volumio[1138]: info: CoreCommandRouter::volumioGetState May 02 23:57:33 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:57:33 volumior volumiobt[1964]: [59B blob data] May 02 23:57:33 volumior volumio[1138]: info: MRS: Getting audio outputs on start May 02 23:57:33 volumior volumio[1138]: info: MRS: Requesting all other devices output May 02 23:57:34 volumior sudo[2035]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 02 23:57:34 volumior sudo[2035]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:34 volumior sudo[2035]: pam_unix(sudo:session): session closed for user root May 02 23:57:34 volumior sudo[2038]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 02 23:57:34 volumior sudo[2038]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:34 volumior sudo[2038]: pam_unix(sudo:session): session closed for user root May 02 23:57:34 volumior volumio[1138]: 0+0 records in May 02 23:57:34 volumior volumio[1138]: 0+0 records out May 02 23:57:34 volumior volumio[1138]: 0 bytes copied, 0.000101655 s, 0.0 kB/s May 02 23:57:34 volumior volumio[1138]: verbose: New Socket.io Connection to 192.168.0.123 from 192.168.0.114 UA: Mozilla/5.0 (Linux; Android 14; SM-G998B Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.60 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 15 May 02 23:57:34 volumior sudo[2046]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.0.101/Multimedia/Musica/Wav /mnt/NAS/NAS May 02 23:57:34 volumior sudo[2046]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:34 volumior kernel: CIFS: Attempting to mount //192.168.0.101/Multimedia/Musica/Wav May 02 23:57:34 volumior kernel: CIFS: VFS: \\192.168.0.101 failed to connect to IPC (rc=-13) May 02 23:57:34 volumior kernel: CIFS: VFS: session abf20aa5 has no tcon available for a dfs referral request May 02 23:57:34 volumior sudo[2046]: pam_unix(sudo:session): session closed for user root May 02 23:57:34 volumior kernel: CIFS: VFS: cifs_mount failed w/return code = -13 May 02 23:57:34 volumior volumio[1138]: info: Cannot mount NAS at system boot, trial number 4 ,stopping May 02 23:57:34 volumior sudo[2052]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 02 23:57:34 volumior sudo[2052]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:34 volumior sudo[2052]: pam_unix(sudo:session): session closed for user root May 02 23:57:34 volumior sudo[2055]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 02 23:57:34 volumior sudo[2055]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:34 volumior sudo[2055]: pam_unix(sudo:session): session closed for user root May 02 23:57:34 volumior volumio[1138]: verbose: New Socket.io Connection to 192.168.0.123 from 192.168.0.114 UA: Mozilla/5.0 (Linux; Android 14; SM-G998B Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.60 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 16 May 02 23:57:34 volumior volumio[1138]: info: CoreCommandRouter::volumioGetState May 02 23:57:34 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:57:34 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 02 23:57:34 volumior volumio[1138]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom May 02 23:57:34 volumior volumio[1138]: info: Listing playlists May 02 23:57:34 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 02 23:57:34 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 02 23:57:34 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 02 23:57:34 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 02 23:57:35 volumior volumio[1138]: 0+0 records in May 02 23:57:35 volumior volumio[1138]: 0+0 records out May 02 23:57:35 volumior volumio[1138]: 0 bytes copied, 9.8971e-05 s, 0.0 kB/s May 02 23:57:35 volumior volumio[1138]: info: TidalConnect service started! May 02 23:57:35 volumior volumio[1138]: [Metrics] CommandRouter: 29s 194.15ms May 02 23:57:35 volumior volumio[1138]: info: CoreCommandRouter::volumiosetStartupVolume May 02 23:57:35 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:35 volumior volumio[1138]: info: VolumeController:: Setting startup Volume 50 May 02 23:57:35 volumior volumio[1138]: info: VolumeController::SetAlsaVolume50 May 02 23:57:35 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:35 volumior volumio[1138]: info: CoreCommandRouter::Close All Modals sent May 02 23:57:35 volumior volumio[1138]: info: CoreCommandRouter::Close All Modals sent May 02 23:57:35 volumior volumio[1138]: info: CoreStateMachine::pushState May 02 23:57:35 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:57:35 volumior volumio[1138]: info: CoreCommandRouter::volumioPushState May 02 23:57:35 volumior volumio[1138]: info: MRS: Pushing multiroomSync output update for this device May 02 23:57:35 volumior volumio[1138]: info: MRS: Pushing multiroomSync output May 02 23:57:35 volumior volumio[1138]: info: PeppyMeterBasic ---peppymeterbasic status stop May 02 23:57:35 volumior volumio[1138]: info: PeppySpectrum ---peppyspectrum status stop May 02 23:57:35 volumior sudo[2067]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service May 02 23:57:35 volumior sudo[2067]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:35 volumior volumio[1138]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 May 02 23:57:35 volumior volumio[1138]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 02 23:57:35 volumior volumio[1138]: info: FusionDsp - ---- read samplerate from file: 44100 May 02 23:57:35 volumior volumio[1138]: info: camilladsp service terminated, instance 1 May 02 23:57:35 volumior sudo[2070]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service May 02 23:57:35 volumior sudo[2070]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:57:35 volumior volumio[1138]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 02 23:57:35 volumior sudo[2067]: pam_unix(sudo:session): session closed for user root May 02 23:57:35 volumior volumio[1138]: info: camilladsp service started and running in background, instance 1 May 02 23:57:35 volumior volumio[1138]: info: peppymeterbasic Daemon Stop May 02 23:57:35 volumior sudo[2070]: pam_unix(sudo:session): session closed for user root May 02 23:57:35 volumior volumio[1138]: info: peppyspectrum Daemon Stop May 02 23:57:36 volumior volumio[1138]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable May 02 23:57:36 volumior volumio[1138]: 2+0 records in May 02 23:57:36 volumior volumio[1138]: 2+0 records out May 02 23:57:36 volumior volumio[1138]: 65536 bytes (66 kB, 64 KiB) copied, 0.000332241 s, 197 MB/s May 02 23:57:36 volumior volumio[1138]: info: CoreCommandRouter::volumioPlay May 02 23:57:36 volumior volumio[1138]: info: CoreStateMachine::play index undefined May 02 23:57:36 volumior volumio[1138]: info: CoreStateMachine::setConsumeUpdateService undefined May 02 23:57:36 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:57:36 volumior volumio[1138]: info: CoreStateMachine::startPlaybackTimer May 02 23:57:36 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:57:36 volumior volumio[1138]: info: [1746223056189] ControllerSpotify::clearAddPlayTrack May 02 23:57:36 volumior volumio[1138]: info: Sending Spotify command with payload to local API: /player/play May 02 23:57:36 volumior go-librespot[1412]: time="2025-05-02T23:57:36+02:00" level=debug msg="resolved context of track" uri="spotify:track:1YqJSpIxdavjQ8BxAttU0r" May 02 23:57:36 volumior go-librespot[1412]: time="2025-05-02T23:57:36+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:1YqJSpIxdavjQ8BxAttU0r" May 02 23:57:36 volumior go-librespot[1412]: time="2025-05-02T23:57:36+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:1YqJSpIxdavjQ8BxAttU0r" May 02 23:57:36 volumior go-librespot[1412]: time="2025-05-02T23:57:36+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 02 23:57:36 volumior go-librespot[1412]: time="2025-05-02T23:57:36+02:00" level=trace msg="emitting websocket event: will_play" May 02 23:57:36 volumior volumio[1138]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1YqJSpIxdavjQ8BxAttU0r","play_origin":"go-librespot"}} May 02 23:57:36 volumior go-librespot[1412]: time="2025-05-02T23:57:36+02:00" level=debug msg="selected format OGG_VORBIS_320 (53cc3579e982576e87bd44db9052f914e1f74b55)" uri="spotify:track:1YqJSpIxdavjQ8BxAttU0r" May 02 23:57:36 volumior go-librespot[1412]: time="2025-05-02T23:57:36+02:00" level=debug msg="requested aes key for file 53cc3579e982576e87bd44db9052f914e1f74b55, gid: 1YqJSpIxdavjQ8BxAttU0r" May 02 23:57:36 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable May 02 23:57:36 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 02 23:57:36 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect May 02 23:57:36 volumior go-librespot[1412]: time="2025-05-02T23:57:36+02:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:1YqJSpIxdavjQ8BxAttU0r: failed retrieving audio key: failed retrieving aes key with code 1" May 02 23:57:36 volumior volumio[1138]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error May 02 23:57:36 volumior volumio[1138]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable May 02 23:57:36 volumior volumio[1138]: 2+0 records in May 02 23:57:36 volumior volumio[1138]: 2+0 records out May 02 23:57:36 volumior volumio[1138]: 65536 bytes (66 kB, 64 KiB) copied, 0.000310465 s, 211 MB/s May 02 23:57:37 volumior volumio[1138]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable May 02 23:57:37 volumior volumio[1138]: 1+1 records in May 02 23:57:37 volumior volumio[1138]: 1+1 records out May 02 23:57:37 volumior volumio[1138]: 61712 bytes (62 kB, 60 KiB) copied, 0.000308225 s, 200 MB/s May 02 23:57:37 volumior systemd[1]: systemd-timedated.service: Succeeded. May 02 23:57:37 volumior volumio[1138]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable May 02 23:57:37 volumior volumio[1138]: 2+0 records in May 02 23:57:37 volumior volumio[1138]: 2+0 records out May 02 23:57:37 volumior volumio[1138]: 65536 bytes (66 kB, 64 KiB) copied, 0.000307244 s, 213 MB/s May 02 23:57:38 volumior volumio[1138]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable May 02 23:57:38 volumior volumio[1138]: 2+0 records in May 02 23:57:38 volumior volumio[1138]: 2+0 records out May 02 23:57:38 volumior volumio[1138]: 65536 bytes (66 kB, 64 KiB) copied, 0.000310375 s, 211 MB/s May 02 23:57:38 volumior volumio[1138]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable May 02 23:57:38 volumior volumio[1138]: 1+1 records in May 02 23:57:38 volumior volumio[1138]: 1+1 records out May 02 23:57:38 volumior volumio[1138]: 61712 bytes (62 kB, 60 KiB) copied, 0.00033252 s, 186 MB/s May 02 23:57:39 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 02 23:57:39 volumior volumio[1138]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 17 May 02 23:57:39 volumior volumio[1138]: info: CoreCommandRouter::volumioGetState May 02 23:57:39 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:57:39 volumior volumio[1138]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable May 02 23:57:39 volumior volumio[1138]: 2+0 records in May 02 23:57:39 volumior volumio[1138]: 2+0 records out May 02 23:57:39 volumior volumio[1138]: 65536 bytes (66 kB, 64 KiB) copied, 0.000320393 s, 205 MB/s May 02 23:57:39 volumior volumio[1138]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable May 02 23:57:39 volumior volumio[1138]: 2+0 records in May 02 23:57:39 volumior volumio[1138]: 2+0 records out May 02 23:57:39 volumior volumio[1138]: 65536 bytes (66 kB, 64 KiB) copied, 0.00031419 s, 209 MB/s May 02 23:57:39 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 02 23:57:39 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 02 23:57:39 volumior volumio[1138]: info: Discovery: Getting this device information May 02 23:57:39 volumior volumio[1138]: info: CoreCommandRouter::volumioGetState May 02 23:57:39 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:57:39 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 02 23:57:40 volumior volumio[1138]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable May 02 23:57:40 volumior volumio[1138]: 1+1 records in May 02 23:57:40 volumior volumio[1138]: 1+1 records out May 02 23:57:40 volumior volumio[1138]: 61712 bytes (62 kB, 60 KiB) copied, 0.000315209 s, 196 MB/s May 02 23:57:40 volumior volumio[1138]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable May 02 23:57:40 volumior volumio[1138]: 2+0 records in May 02 23:57:40 volumior volumio[1138]: 2+0 records out May 02 23:57:40 volumior volumio[1138]: 65536 bytes (66 kB, 64 KiB) copied, 0.000322746 s, 203 MB/s May 02 23:57:41 volumior volumio[1138]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable May 02 23:57:41 volumior volumio[1138]: 1+1 records in May 02 23:57:41 volumior volumio[1138]: 1+1 records out May 02 23:57:41 volumior volumio[1138]: 61712 bytes (62 kB, 60 KiB) copied, 0.0003056 s, 202 MB/s May 02 23:57:41 volumior volumio[1138]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable May 02 23:57:41 volumior volumio[1138]: 2+0 records in May 02 23:57:41 volumior volumio[1138]: 2+0 records out May 02 23:57:41 volumior volumio[1138]: 65536 bytes (66 kB, 64 KiB) copied, 0.000304026 s, 216 MB/s May 02 23:57:42 volumior volumio[1138]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable May 02 23:57:42 volumior volumio[1138]: 2+0 records in May 02 23:57:42 volumior volumio[1138]: 2+0 records out May 02 23:57:42 volumior volumio[1138]: 65536 bytes (66 kB, 64 KiB) copied, 0.000302175 s, 217 MB/s May 02 23:57:42 volumior volumio[1138]: info: BOOT COMPLETED May 02 23:57:42 volumior volumio[1138]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable May 02 23:57:42 volumior volumio[1138]: 1+1 records in May 02 23:57:42 volumior volumio[1138]: 1+1 records out May 02 23:57:42 volumior volumio[1138]: 61712 bytes (62 kB, 60 KiB) copied, 0.0003196 s, 193 MB/s May 02 23:57:43 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 02 23:57:43 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 23:57:43 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 02 23:57:43 volumior volumio-remote-updater[707]: No test mode May 02 23:57:43 volumior volumio-remote-updater[707]: No alpha test mode May 02 23:57:43 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled May 02 23:57:43 volumior volumio[1138]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable May 02 23:57:43 volumior volumio[1138]: 2+0 records in May 02 23:57:43 volumior volumio[1138]: 2+0 records out May 02 23:57:43 volumior volumio[1138]: 65536 bytes (66 kB, 64 KiB) copied, 0.000324526 s, 202 MB/s May 02 23:57:43 volumior volumio[1138]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} May 02 23:57:43 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache May 02 23:57:43 volumior volumio[1138]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable May 02 23:57:43 volumior volumio[1138]: 2+0 records in May 02 23:57:43 volumior volumio[1138]: 2+0 records out May 02 23:57:43 volumior volumio[1138]: 65536 bytes (66 kB, 64 KiB) copied, 0.000319082 s, 205 MB/s May 02 23:57:43 volumior volumio[1138]: info: CoreCommandRouter::volumioGetVisibleSources May 02 23:57:43 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 02 23:57:44 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:44 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 23:57:44 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam May 02 23:57:44 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam May 02 23:57:44 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam May 02 23:57:44 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 02 23:57:44 volumior volumio[1138]: info: CoreCommandRouter::volumioGetBrowseSources May 02 23:57:44 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 02 23:57:44 volumior volumio[1138]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable May 02 23:57:44 volumior volumio[1138]: 1+1 records in May 02 23:57:44 volumior volumio[1138]: 1+1 records out May 02 23:57:44 volumior volumio[1138]: 61712 bytes (62 kB, 60 KiB) copied, 0.000314565 s, 196 MB/s May 02 23:57:44 volumior volumio[1138]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable May 02 23:57:44 volumior volumio[1138]: 2+0 records in May 02 23:57:44 volumior volumio[1138]: 2+0 records out May 02 23:57:44 volumior volumio[1138]: 65536 bytes (66 kB, 64 KiB) copied, 0.00032136 s, 204 MB/s May 02 23:57:45 volumior go-librespot[1412]: time="2025-05-02T23:57:45+02:00" level=trace msg="sent dealer ping" May 02 23:57:45 volumior go-librespot[1412]: time="2025-05-02T23:57:45+02:00" level=trace msg="received dealer pong" May 02 23:57:45 volumior volumio[1138]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable May 02 23:57:45 volumior volumio[1138]: 2+0 records in May 02 23:57:45 volumior volumio[1138]: 2+0 records out May 02 23:57:45 volumior volumio[1138]: 65536 bytes (66 kB, 64 KiB) copied, 0.000307881 s, 213 MB/s May 02 23:57:45 volumior volumio[1138]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable May 02 23:57:45 volumior volumio[1138]: 1+1 records in May 02 23:57:45 volumior volumio[1138]: 1+1 records out May 02 23:57:45 volumior volumio[1138]: 61712 bytes (62 kB, 60 KiB) copied, 0.000326027 s, 189 MB/s May 02 23:57:46 volumior volumio[1138]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable May 02 23:57:46 volumior volumio[1138]: 2+0 records in May 02 23:57:46 volumior volumio[1138]: 2+0 records out May 02 23:57:46 volumior volumio[1138]: 65536 bytes (66 kB, 64 KiB) copied, 0.000523808 s, 125 MB/s May 02 23:57:46 volumior volumio[1138]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable May 02 23:57:46 volumior volumio[1138]: 1+1 records in May 02 23:57:46 volumior volumio[1138]: 1+1 records out May 02 23:57:46 volumior volumio[1138]: 61712 bytes (62 kB, 60 KiB) copied, 0.000321918 s, 192 MB/s May 02 23:57:47 volumior volumio[1138]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable May 02 23:57:47 volumior volumio[1138]: 2+0 records in May 02 23:57:47 volumior volumio[1138]: 2+0 records out May 02 23:57:47 volumior volumio[1138]: 65536 bytes (66 kB, 64 KiB) copied, 0.00031366 s, 209 MB/s May 02 23:57:48 volumior volumio[1138]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable May 02 23:57:48 volumior volumio[1138]: 2+0 records in May 02 23:57:48 volumior volumio[1138]: 2+0 records out May 02 23:57:48 volumior volumio[1138]: 65536 bytes (66 kB, 64 KiB) copied, 0.000311402 s, 210 MB/s May 02 23:57:48 volumior volumio[1138]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable May 02 23:57:48 volumior volumio[1138]: 1+1 records in May 02 23:57:48 volumior volumio[1138]: 1+1 records out May 02 23:57:48 volumior volumio[1138]: 61712 bytes (62 kB, 60 KiB) copied, 0.00030792 s, 200 MB/s May 02 23:57:49 volumior volumio[1138]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable May 02 23:57:49 volumior volumio[1138]: 2+0 records in May 02 23:57:49 volumior volumio[1138]: 2+0 records out May 02 23:57:49 volumior volumio[1138]: 65536 bytes (66 kB, 64 KiB) copied, 0.000314568 s, 208 MB/s May 02 23:57:49 volumior volumio[1138]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable May 02 23:57:49 volumior volumio[1138]: 2+30 records in May 02 23:57:49 volumior volumio[1138]: 2+30 records out May 02 23:57:49 volumior volumio[1138]: 182512 bytes (183 kB, 178 KiB) copied, 0.000520385 s, 351 MB/s May 02 23:57:50 volumior volumio[1138]: 0+0 records in May 02 23:57:50 volumior volumio[1138]: 0+0 records out May 02 23:57:50 volumior volumio[1138]: 0 bytes copied, 9.8049e-05 s, 0.0 kB/s May 02 23:57:50 volumior volumio[1138]: info: Executing endpoint metavolumio May 02 23:57:50 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 02 23:57:50 volumior volumio[1138]: 0+0 records in May 02 23:57:50 volumior volumio[1138]: 0+0 records out May 02 23:57:50 volumior volumio[1138]: 0 bytes copied, 9.9752e-05 s, 0.0 kB/s May 02 23:57:51 volumior volumio[1138]: 0+0 records in May 02 23:57:51 volumior volumio[1138]: 0+0 records out May 02 23:57:51 volumior volumio[1138]: 0 bytes copied, 0.000106251 s, 0.0 kB/s May 02 23:57:51 volumior volumio[1138]: 0+0 records in May 02 23:57:51 volumior volumio[1138]: 0+0 records out May 02 23:57:51 volumior volumio[1138]: 0 bytes copied, 9.9382e-05 s, 0.0 kB/s May 02 23:57:52 volumior volumio[1138]: 0+0 records in May 02 23:57:52 volumior volumio[1138]: 0+0 records out May 02 23:57:52 volumior volumio[1138]: 0 bytes copied, 0.000114862 s, 0.0 kB/s May 02 23:57:52 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 02 23:57:52 volumior volumio[1138]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined May 02 23:57:52 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates May 02 23:57:52 volumior volumio[1138]: info: Received Get System Version May 02 23:57:52 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 02 23:57:52 volumior volumio[1138]: info: Received Get System Info May 02 23:57:52 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 02 23:57:52 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 02 23:57:52 volumior volumio[1138]: info: Discovery: Getting this device information May 02 23:57:52 volumior volumio[1138]: info: CoreCommandRouter::volumioGetState May 02 23:57:52 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:57:52 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 02 23:57:52 volumior volumio[1138]: 0+0 records in May 02 23:57:52 volumior volumio[1138]: 0+0 records out May 02 23:57:52 volumior volumio[1138]: 0 bytes copied, 0.000101067 s, 0.0 kB/s May 02 23:57:53 volumior volumio[1138]: 0+0 records in May 02 23:57:53 volumior volumio[1138]: 0+0 records out May 02 23:57:53 volumior volumio[1138]: 0 bytes copied, 9.716e-05 s, 0.0 kB/s May 02 23:57:53 volumior volumio[1138]: 0+0 records in May 02 23:57:53 volumior volumio[1138]: 0+0 records out May 02 23:57:53 volumior volumio[1138]: 0 bytes copied, 0.000100049 s, 0.0 kB/s May 02 23:57:54 volumior volumio[1138]: 0+0 records in May 02 23:57:54 volumior volumio[1138]: 0+0 records out May 02 23:57:54 volumior volumio[1138]: 0 bytes copied, 9.9123e-05 s, 0.0 kB/s May 02 23:57:54 volumior volumio[1138]: 0+0 records in May 02 23:57:54 volumior volumio[1138]: 0+0 records out May 02 23:57:54 volumior volumio[1138]: 0 bytes copied, 9.8679e-05 s, 0.0 kB/s May 02 23:57:55 volumior volumio[1138]: 0+0 records in May 02 23:57:55 volumior volumio[1138]: 0+0 records out May 02 23:57:55 volumior volumio[1138]: 0 bytes copied, 0.000122195 s, 0.0 kB/s May 02 23:57:55 volumior volumio[1138]: 0+0 records in May 02 23:57:55 volumior volumio[1138]: 0+0 records out May 02 23:57:55 volumior volumio[1138]: 0 bytes copied, 0.000100271 s, 0.0 kB/s May 02 23:57:56 volumior volumio[1138]: 0+0 records in May 02 23:57:56 volumior volumio[1138]: 0+0 records out May 02 23:57:56 volumior volumio[1138]: 0 bytes copied, 0.00010029 s, 0.0 kB/s May 02 23:57:56 volumior volumio[1138]: 0+0 records in May 02 23:57:56 volumior volumio[1138]: 0+0 records out May 02 23:57:56 volumior volumio[1138]: 0 bytes copied, 0.000100512 s, 0.0 kB/s May 02 23:57:57 volumior volumio[1138]: info: Executing endpoint metavolumio May 02 23:57:57 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 02 23:57:57 volumior volumio[1138]: 0+0 records in May 02 23:57:57 volumior volumio[1138]: 0+0 records out May 02 23:57:57 volumior volumio[1138]: 0 bytes copied, 0.00010053 s, 0.0 kB/s May 02 23:57:58 volumior volumio[1138]: 0+0 records in May 02 23:57:58 volumior volumio[1138]: 0+0 records out May 02 23:57:58 volumior volumio[1138]: 0 bytes copied, 0.00010029 s, 0.0 kB/s May 02 23:57:58 volumior volumio[1138]: 0+0 records in May 02 23:57:58 volumior volumio[1138]: 0+0 records out May 02 23:57:58 volumior volumio[1138]: 0 bytes copied, 0.000117493 s, 0.0 kB/s May 02 23:57:59 volumior volumio[1138]: 0+0 records in May 02 23:57:59 volumior volumio[1138]: 0+0 records out May 02 23:57:59 volumior volumio[1138]: 0 bytes copied, 9.536e-05 s, 0.0 kB/s May 02 23:57:59 volumior volumio[1138]: 0+0 records in May 02 23:57:59 volumior volumio[1138]: 0+0 records out May 02 23:57:59 volumior volumio[1138]: 0 bytes copied, 0.000100137 s, 0.0 kB/s May 02 23:58:00 volumior volumio[1138]: 0+0 records in May 02 23:58:00 volumior volumio[1138]: 0+0 records out May 02 23:58:00 volumior volumio[1138]: 0 bytes copied, 9.9101e-05 s, 0.0 kB/s May 02 23:58:00 volumior volumio[1138]: 0+0 records in May 02 23:58:00 volumior volumio[1138]: 0+0 records out May 02 23:58:00 volumior volumio[1138]: 0 bytes copied, 9.9175e-05 s, 0.0 kB/s May 02 23:58:01 volumior volumio[1138]: 0+0 records in May 02 23:58:01 volumior volumio[1138]: 0+0 records out May 02 23:58:01 volumior volumio[1138]: 0 bytes copied, 9.9749e-05 s, 0.0 kB/s May 02 23:58:01 volumior volumio[1138]: 0+0 records in May 02 23:58:01 volumior volumio[1138]: 0+0 records out May 02 23:58:01 volumior volumio[1138]: 0 bytes copied, 0.000100193 s, 0.0 kB/s May 02 23:58:02 volumior volumio[1138]: 0+0 records in May 02 23:58:02 volumior volumio[1138]: 0+0 records out May 02 23:58:02 volumior volumio[1138]: 0 bytes copied, 9.8824e-05 s, 0.0 kB/s May 02 23:58:02 volumior volumio[1138]: 0+0 records in May 02 23:58:02 volumior volumio[1138]: 0+0 records out May 02 23:58:02 volumior volumio[1138]: 0 bytes copied, 0.000101749 s, 0.0 kB/s May 02 23:58:03 volumior volumio[1138]: 0+0 records in May 02 23:58:03 volumior volumio[1138]: 0+0 records out May 02 23:58:03 volumior volumio[1138]: 0 bytes copied, 9.7695e-05 s, 0.0 kB/s May 02 23:58:03 volumior volumio[1138]: 0+0 records in May 02 23:58:03 volumior volumio[1138]: 0+0 records out May 02 23:58:03 volumior volumio[1138]: 0 bytes copied, 0.000101564 s, 0.0 kB/s May 02 23:58:04 volumior volumio[1138]: 0+0 records in May 02 23:58:04 volumior volumio[1138]: 0+0 records out May 02 23:58:04 volumior volumio[1138]: 0 bytes copied, 0.000102287 s, 0.0 kB/s May 02 23:58:04 volumior volumio[1138]: 0+0 records in May 02 23:58:04 volumior volumio[1138]: 0+0 records out May 02 23:58:04 volumior volumio[1138]: 0 bytes copied, 9.8843e-05 s, 0.0 kB/s May 02 23:58:05 volumior volumio[1138]: 0+0 records in May 02 23:58:05 volumior volumio[1138]: 0+0 records out May 02 23:58:05 volumior volumio[1138]: 0 bytes copied, 0.000100583 s, 0.0 kB/s May 02 23:58:05 volumior volumio[1138]: info: CoreCommandRouter::volumioGetState May 02 23:58:05 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:58:05 volumior volumio[1138]: 0+0 records in May 02 23:58:05 volumior volumio[1138]: 0+0 records out May 02 23:58:05 volumior volumio[1138]: 0 bytes copied, 0.000100195 s, 0.0 kB/s May 02 23:58:05 volumior sudo[2457]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 02 23:58:05 volumior sudo[2457]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:58:05 volumior sudo[2457]: pam_unix(sudo:session): session closed for user root May 02 23:58:05 volumior sudo[2460]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 02 23:58:05 volumior sudo[2460]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:58:05 volumior sudo[2460]: pam_unix(sudo:session): session closed for user root May 02 23:58:05 volumior volumio[1138]: verbose: New Socket.io Connection to 192.168.0.123 from 192.168.0.114 UA: Mozilla/5.0 (Linux; Android 14; SM-G998B Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.60 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 12 May 02 23:58:06 volumior volumio[1138]: info: CoreCommandRouter::volumioGetVisibleSources May 02 23:58:06 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 02 23:58:06 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 02 23:58:06 volumior volumio[1138]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom May 02 23:58:06 volumior volumio[1138]: info: CoreCommandRouter::volumioGetState May 02 23:58:06 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:58:06 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 02 23:58:06 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 02 23:58:06 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 02 23:58:06 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 02 23:58:06 volumior sudo[2463]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 02 23:58:06 volumior sudo[2463]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:58:06 volumior sudo[2463]: pam_unix(sudo:session): session closed for user root May 02 23:58:06 volumior sudo[2466]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 02 23:58:06 volumior sudo[2466]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:58:06 volumior sudo[2466]: pam_unix(sudo:session): session closed for user root May 02 23:58:06 volumior volumio[1138]: 0+0 records in May 02 23:58:06 volumior volumio[1138]: 0+0 records out May 02 23:58:06 volumior volumio[1138]: 0 bytes copied, 0.000100788 s, 0.0 kB/s May 02 23:58:06 volumior volumio[1138]: verbose: New Socket.io Connection to 192.168.0.123 from 192.168.0.114 UA: Mozilla/5.0 (Linux; Android 14; SM-G998B Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.60 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 13 May 02 23:58:06 volumior volumio[1138]: info: CoreCommandRouter::volumioGetState May 02 23:58:06 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:58:06 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 02 23:58:06 volumior volumio[1138]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom May 02 23:58:06 volumior volumio[1138]: info: Listing playlists May 02 23:58:06 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 02 23:58:06 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 02 23:58:06 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 02 23:58:06 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 02 23:58:06 volumior volumio[1138]: 0+0 records in May 02 23:58:06 volumior volumio[1138]: 0+0 records out May 02 23:58:06 volumior volumio[1138]: 0 bytes copied, 9.7639e-05 s, 0.0 kB/s May 02 23:58:07 volumior volumio[1138]: 0+0 records in May 02 23:58:07 volumior volumio[1138]: 0+0 records out May 02 23:58:07 volumior volumio[1138]: 0 bytes copied, 0.000106787 s, 0.0 kB/s May 02 23:58:07 volumior volumio[1138]: 0+0 records in May 02 23:58:07 volumior volumio[1138]: 0+0 records out May 02 23:58:07 volumior volumio[1138]: 0 bytes copied, 9.9584e-05 s, 0.0 kB/s May 02 23:58:08 volumior volumio[1138]: 0+0 records in May 02 23:58:08 volumior volumio[1138]: 0+0 records out May 02 23:58:08 volumior volumio[1138]: 0 bytes copied, 9.9973e-05 s, 0.0 kB/s May 02 23:58:08 volumior volumio[1138]: info: CoreCommandRouter::volumioGetVisibleSources May 02 23:58:08 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 02 23:58:08 volumior volumio[1138]: 0+0 records in May 02 23:58:08 volumior volumio[1138]: 0+0 records out May 02 23:58:08 volumior volumio[1138]: 0 bytes copied, 9.9658e-05 s, 0.0 kB/s May 02 23:58:09 volumior volumio[1138]: 0+0 records in May 02 23:58:09 volumior volumio[1138]: 0+0 records out May 02 23:58:09 volumior volumio[1138]: 0 bytes copied, 9.8937e-05 s, 0.0 kB/s May 02 23:58:09 volumior volumio[1138]: 0+0 records in May 02 23:58:09 volumior volumio[1138]: 0+0 records out May 02 23:58:09 volumior volumio[1138]: 0 bytes copied, 0.000105844 s, 0.0 kB/s May 02 23:58:09 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 02 23:58:09 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 02 23:58:09 volumior volumio[1138]: info: Discovery: Getting this device information May 02 23:58:09 volumior volumio[1138]: info: CoreCommandRouter::volumioGetState May 02 23:58:09 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:58:09 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 02 23:58:10 volumior volumio[1138]: 0+0 records in May 02 23:58:10 volumior volumio[1138]: 0+0 records out May 02 23:58:10 volumior volumio[1138]: 0 bytes copied, 0.00010925 s, 0.0 kB/s May 02 23:58:10 volumior volumio[1138]: 0+0 records in May 02 23:58:10 volumior volumio[1138]: 0+0 records out May 02 23:58:10 volumior volumio[1138]: 0 bytes copied, 0.000100085 s, 0.0 kB/s May 02 23:58:11 volumior volumio[1138]: 0+0 records in May 02 23:58:11 volumior volumio[1138]: 0+0 records out May 02 23:58:11 volumior volumio[1138]: 0 bytes copied, 0.000100474 s, 0.0 kB/s May 02 23:58:11 volumior volumio[1138]: 0+0 records in May 02 23:58:11 volumior volumio[1138]: 0+0 records out May 02 23:58:11 volumior volumio[1138]: 0 bytes copied, 0.00011425 s, 0.0 kB/s May 02 23:58:12 volumior volumio[1138]: 0+0 records in May 02 23:58:12 volumior volumio[1138]: 0+0 records out May 02 23:58:12 volumior volumio[1138]: 0 bytes copied, 0.000100011 s, 0.0 kB/s May 02 23:58:12 volumior volumio[1138]: 0+0 records in May 02 23:58:12 volumior volumio[1138]: 0+0 records out May 02 23:58:12 volumior volumio[1138]: 0 bytes copied, 9.8678e-05 s, 0.0 kB/s May 02 23:58:13 volumior volumio[1138]: 0+0 records in May 02 23:58:13 volumior volumio[1138]: 0+0 records out May 02 23:58:13 volumior volumio[1138]: 0 bytes copied, 0.000108436 s, 0.0 kB/s May 02 23:58:13 volumior volumio[1138]: 0+0 records in May 02 23:58:13 volumior volumio[1138]: 0+0 records out May 02 23:58:13 volumior volumio[1138]: 0 bytes copied, 0.000100178 s, 0.0 kB/s May 02 23:58:14 volumior volumio[1138]: 0+0 records in May 02 23:58:14 volumior volumio[1138]: 0+0 records out May 02 23:58:14 volumior volumio[1138]: 0 bytes copied, 9.8901e-05 s, 0.0 kB/s May 02 23:58:15 volumior volumio[1138]: 0+0 records in May 02 23:58:15 volumior volumio[1138]: 0+0 records out May 02 23:58:15 volumior volumio[1138]: 0 bytes copied, 9.7882e-05 s, 0.0 kB/s May 02 23:58:15 volumior go-librespot[1412]: time="2025-05-02T23:58:15+02:00" level=trace msg="sent dealer ping" May 02 23:58:15 volumior go-librespot[1412]: time="2025-05-02T23:58:15+02:00" level=trace msg="received dealer pong" May 02 23:58:15 volumior volumio[1138]: 0+0 records in May 02 23:58:15 volumior volumio[1138]: 0+0 records out May 02 23:58:15 volumior volumio[1138]: 0 bytes copied, 0.000100141 s, 0.0 kB/s May 02 23:58:16 volumior volumio[1138]: 0+0 records in May 02 23:58:16 volumior volumio[1138]: 0+0 records out May 02 23:58:16 volumior volumio[1138]: 0 bytes copied, 0.0001134 s, 0.0 kB/s May 02 23:58:16 volumior volumio[1138]: 0+0 records in May 02 23:58:16 volumior volumio[1138]: 0+0 records out May 02 23:58:16 volumior volumio[1138]: 0 bytes copied, 9.7401e-05 s, 0.0 kB/s May 02 23:58:17 volumior volumio[1138]: 0+0 records in May 02 23:58:17 volumior volumio[1138]: 0+0 records out May 02 23:58:17 volumior volumio[1138]: 0 bytes copied, 9.9698e-05 s, 0.0 kB/s May 02 23:58:17 volumior volumio[1138]: 0+0 records in May 02 23:58:17 volumior volumio[1138]: 0+0 records out May 02 23:58:17 volumior volumio[1138]: 0 bytes copied, 0.000115271 s, 0.0 kB/s May 02 23:58:18 volumior volumio[1138]: 0+0 records in May 02 23:58:18 volumior volumio[1138]: 0+0 records out May 02 23:58:18 volumior volumio[1138]: 0 bytes copied, 0.000114179 s, 0.0 kB/s May 02 23:58:18 volumior volumio[1138]: 0+0 records in May 02 23:58:18 volumior volumio[1138]: 0+0 records out May 02 23:58:18 volumior volumio[1138]: 0 bytes copied, 9.9642e-05 s, 0.0 kB/s May 02 23:58:19 volumior volumio[1138]: 0+0 records in May 02 23:58:19 volumior volumio[1138]: 0+0 records out May 02 23:58:19 volumior volumio[1138]: 0 bytes copied, 0.00010042 s, 0.0 kB/s May 02 23:58:19 volumior volumio[1138]: 0+0 records in May 02 23:58:19 volumior volumio[1138]: 0+0 records out May 02 23:58:19 volumior volumio[1138]: 0 bytes copied, 9.7383e-05 s, 0.0 kB/s May 02 23:58:20 volumior volumio[1138]: 0+0 records in May 02 23:58:20 volumior volumio[1138]: 0+0 records out May 02 23:58:20 volumior volumio[1138]: 0 bytes copied, 9.8902e-05 s, 0.0 kB/s May 02 23:58:20 volumior volumio[1138]: 0+0 records in May 02 23:58:20 volumior volumio[1138]: 0+0 records out May 02 23:58:20 volumior volumio[1138]: 0 bytes copied, 0.000100494 s, 0.0 kB/s May 02 23:58:21 volumior volumio[1138]: 0+0 records in May 02 23:58:21 volumior volumio[1138]: 0+0 records out May 02 23:58:21 volumior volumio[1138]: 0 bytes copied, 0.00010018 s, 0.0 kB/s May 02 23:58:21 volumior volumio[1138]: 0+0 records in May 02 23:58:21 volumior volumio[1138]: 0+0 records out May 02 23:58:21 volumior volumio[1138]: 0 bytes copied, 0.000100938 s, 0.0 kB/s May 02 23:58:22 volumior volumio[1138]: 0+0 records in May 02 23:58:22 volumior volumio[1138]: 0+0 records out May 02 23:58:22 volumior volumio[1138]: 0 bytes copied, 9.8661e-05 s, 0.0 kB/s May 02 23:58:22 volumior volumio[1138]: info: VolumeController::SetAlsaVolume60 May 02 23:58:22 volumior volumio[1138]: info: CoreStateMachine::pushState May 02 23:58:22 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:58:22 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 02 23:58:22 volumior volumio[1138]: info: CoreCommandRouter::volumioPushState May 02 23:58:22 volumior volumio[1138]: info: MRS: Pushing multiroomSync output update for this device May 02 23:58:22 volumior volumio[1138]: info: MRS: Pushing multiroomSync output May 02 23:58:22 volumior volumio[1138]: info: PeppyMeterBasic ---peppymeterbasic status stop May 02 23:58:22 volumior volumio[1138]: info: PeppySpectrum ---peppyspectrum status stop May 02 23:58:22 volumior sudo[2661]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service May 02 23:58:22 volumior sudo[2661]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:58:22 volumior volumio[1138]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 May 02 23:58:22 volumior volumio[1138]: SPOTIFY: SPOTIFY VOLUME 50 May 02 23:58:22 volumior volumio[1138]: SPOTIFY: VOLUMIO VOLUME 60 May 02 23:58:22 volumior volumio[1138]: SPOTIFY: DELTA VOLUME ENOUGH: true May 02 23:58:22 volumior volumio[1138]: info: Setting Spotify Volume from Volumio: 60 May 02 23:58:22 volumior sudo[2664]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service May 02 23:58:22 volumior sudo[2664]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:58:22 volumior sudo[2661]: pam_unix(sudo:session): session closed for user root May 02 23:58:22 volumior volumio[1138]: info: VolumeController::SetAlsaVolume70 May 02 23:58:22 volumior sudo[2664]: pam_unix(sudo:session): session closed for user root May 02 23:58:22 volumior volumio[1138]: info: CoreStateMachine::pushState May 02 23:58:22 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:58:22 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 02 23:58:22 volumior volumio[1138]: info: CoreCommandRouter::volumioPushState May 02 23:58:22 volumior volumio[1138]: info: MRS: Pushing multiroomSync output update for this device May 02 23:58:22 volumior volumio[1138]: info: MRS: Pushing multiroomSync output May 02 23:58:22 volumior volumio[1138]: info: PeppyMeterBasic ---peppymeterbasic status stop May 02 23:58:22 volumior volumio[1138]: info: PeppySpectrum ---peppyspectrum status stop May 02 23:58:22 volumior sudo[2668]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service May 02 23:58:22 volumior sudo[2668]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:58:23 volumior volumio[1138]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 May 02 23:58:23 volumior volumio[1138]: SPOTIFY: SPOTIFY VOLUME 60 May 02 23:58:23 volumior volumio[1138]: SPOTIFY: VOLUMIO VOLUME 70 May 02 23:58:23 volumior volumio[1138]: SPOTIFY: DELTA VOLUME ENOUGH: true May 02 23:58:23 volumior volumio[1138]: info: Setting Spotify Volume from Volumio: 70 May 02 23:58:23 volumior sudo[2671]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service May 02 23:58:23 volumior sudo[2671]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 23:58:23 volumior volumio[1138]: info: peppyspectrum Daemon Stop May 02 23:58:23 volumior volumio[1138]: info: peppymeterbasic Daemon Stop May 02 23:58:23 volumior sudo[2668]: pam_unix(sudo:session): session closed for user root May 02 23:58:23 volumior volumio[1138]: 0+0 records in May 02 23:58:23 volumior volumio[1138]: 0+0 records out May 02 23:58:23 volumior volumio[1138]: 0 bytes copied, 0.000117457 s, 0.0 kB/s May 02 23:58:23 volumior sudo[2671]: pam_unix(sudo:session): session closed for user root May 02 23:58:23 volumior volumio[1138]: info: peppyspectrum Daemon Stop May 02 23:58:23 volumior volumio[1138]: info: peppymeterbasic Daemon Stop May 02 23:58:23 volumior volumio[1138]: 0+0 records in May 02 23:58:23 volumior volumio[1138]: 0+0 records out May 02 23:58:23 volumior volumio[1138]: 0 bytes copied, 0.000100032 s, 0.0 kB/s May 02 23:58:24 volumior volumio[1138]: 0+0 records in May 02 23:58:24 volumior volumio[1138]: 0+0 records out May 02 23:58:24 volumior volumio[1138]: 0 bytes copied, 0.000115272 s, 0.0 kB/s May 02 23:58:24 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 02 23:58:24 volumior volumio[1138]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined May 02 23:58:24 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates May 02 23:58:24 volumior volumio[1138]: info: Received Get System Version May 02 23:58:24 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 02 23:58:24 volumior volumio[1138]: info: Received Get System Info May 02 23:58:24 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 02 23:58:24 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 02 23:58:24 volumior volumio[1138]: info: Discovery: Getting this device information May 02 23:58:24 volumior volumio[1138]: info: CoreCommandRouter::volumioGetState May 02 23:58:24 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:58:24 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 02 23:58:24 volumior volumio[1138]: 0+0 records in May 02 23:58:24 volumior volumio[1138]: 0+0 records out May 02 23:58:24 volumior volumio[1138]: 0 bytes copied, 0.000100736 s, 0.0 kB/s May 02 23:58:24 volumior volumio[1138]: SPOTIFY: SETTING SPOTIFY VOLUME 70 May 02 23:58:24 volumior volumio[1138]: info: Sending Spotify command with payload to local API: /player/volume May 02 23:58:24 volumior go-librespot[1412]: time="2025-05-02T23:58:24+02:00" level=debug msg="update volume to 45874/65535" May 02 23:58:25 volumior volumio[1138]: 0+0 records in May 02 23:58:25 volumior volumio[1138]: 0+0 records out May 02 23:58:25 volumior volumio[1138]: 0 bytes copied, 9.9736e-05 s, 0.0 kB/s May 02 23:58:25 volumior volumio[1138]: 0+0 records in May 02 23:58:25 volumior volumio[1138]: 0+0 records out May 02 23:58:25 volumior volumio[1138]: 0 bytes copied, 9.7254e-05 s, 0.0 kB/s May 02 23:58:25 volumior go-librespot[1412]: time="2025-05-02T23:58:25+02:00" level=debug msg="put connect state because VOLUME_CHANGED" May 02 23:58:25 volumior go-librespot[1412]: time="2025-05-02T23:58:25+02:00" level=trace msg="emitting websocket event: volume" May 02 23:58:25 volumior volumio[1138]: SPOTIFY: received: {"type":"volume","data":{"value":70,"max":100}} May 02 23:58:25 volumior volumio[1138]: SPOTIFY: RECEIVED SPOTIFY VOLUME 70 May 02 23:58:26 volumior volumio[1138]: 0+0 records in May 02 23:58:26 volumior volumio[1138]: 0+0 records out May 02 23:58:26 volumior volumio[1138]: 0 bytes copied, 0.000114547 s, 0.0 kB/s May 02 23:58:26 volumior volumio[1138]: 0+0 records in May 02 23:58:26 volumior volumio[1138]: 0+0 records out May 02 23:58:26 volumior volumio[1138]: 0 bytes copied, 9.8899e-05 s, 0.0 kB/s May 02 23:58:27 volumior volumio[1138]: 0+0 records in May 02 23:58:27 volumior volumio[1138]: 0+0 records out May 02 23:58:27 volumior volumio[1138]: 0 bytes copied, 9.9456e-05 s, 0.0 kB/s May 02 23:58:27 volumior volumio[1138]: 0+0 records in May 02 23:58:27 volumior volumio[1138]: 0+0 records out May 02 23:58:27 volumior volumio[1138]: 0 bytes copied, 0.000114862 s, 0.0 kB/s May 02 23:58:28 volumior volumio[1138]: 0+0 records in May 02 23:58:28 volumior volumio[1138]: 0+0 records out May 02 23:58:28 volumior volumio[1138]: 0 bytes copied, 9.964e-05 s, 0.0 kB/s May 02 23:58:28 volumior volumio[1138]: 0+0 records in May 02 23:58:28 volumior volumio[1138]: 0+0 records out May 02 23:58:28 volumior volumio[1138]: 0 bytes copied, 0.000100345 s, 0.0 kB/s May 02 23:58:29 volumior volumio[1138]: 0+0 records in May 02 23:58:29 volumior volumio[1138]: 0+0 records out May 02 23:58:29 volumior volumio[1138]: 0 bytes copied, 0.000104307 s, 0.0 kB/s May 02 23:58:29 volumior volumio[1138]: 0+0 records in May 02 23:58:29 volumior volumio[1138]: 0+0 records out May 02 23:58:29 volumior volumio[1138]: 0 bytes copied, 0.0001019 s, 0.0 kB/s May 02 23:58:30 volumior volumio[1138]: 0+0 records in May 02 23:58:30 volumior volumio[1138]: 0+0 records out May 02 23:58:30 volumior volumio[1138]: 0 bytes copied, 0.000106734 s, 0.0 kB/s May 02 23:58:30 volumior volumio[1138]: 0+0 records in May 02 23:58:30 volumior volumio[1138]: 0+0 records out May 02 23:58:30 volumior volumio[1138]: 0 bytes copied, 9.816e-05 s, 0.0 kB/s May 02 23:58:31 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getHwuuid May 02 23:58:31 volumior volumio[1138]: info: Playing Remote Device: http://192.168.0.123 May 02 23:58:31 volumior volumio[1138]: info: May 02 23:58:31 volumior volumio[1138]: ---------------------------- Client requests Volumio play May 02 23:58:31 volumior volumio[1138]: info: CoreCommandRouter::volumioPlay May 02 23:58:31 volumior volumio[1138]: info: CoreStateMachine::play index undefined May 02 23:58:31 volumior volumio[1138]: info: CoreStateMachine::setConsumeUpdateService undefined May 02 23:58:31 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:58:31 volumior volumio[1138]: info: CoreStateMachine::startPlaybackTimer May 02 23:58:31 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:58:31 volumior volumio[1138]: info: [1746223111121] ControllerSpotify::clearAddPlayTrack May 02 23:58:31 volumior volumio[1138]: info: Sending Spotify command with payload to local API: /player/play May 02 23:58:31 volumior volumio[1138]: info: Done playing: May 02 23:58:31 volumior go-librespot[1412]: time="2025-05-02T23:58:31+02:00" level=debug msg="resolved context of track" uri="spotify:track:1YqJSpIxdavjQ8BxAttU0r" May 02 23:58:31 volumior go-librespot[1412]: time="2025-05-02T23:58:31+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:1YqJSpIxdavjQ8BxAttU0r" May 02 23:58:31 volumior go-librespot[1412]: time="2025-05-02T23:58:31+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:1YqJSpIxdavjQ8BxAttU0r" May 02 23:58:31 volumior go-librespot[1412]: time="2025-05-02T23:58:31+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 02 23:58:31 volumior go-librespot[1412]: time="2025-05-02T23:58:31+02:00" level=trace msg="emitting websocket event: will_play" May 02 23:58:31 volumior volumio[1138]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1YqJSpIxdavjQ8BxAttU0r","play_origin":"go-librespot"}} May 02 23:58:31 volumior go-librespot[1412]: time="2025-05-02T23:58:31+02:00" level=debug msg="selected format OGG_VORBIS_320 (53cc3579e982576e87bd44db9052f914e1f74b55)" uri="spotify:track:1YqJSpIxdavjQ8BxAttU0r" May 02 23:58:31 volumior go-librespot[1412]: time="2025-05-02T23:58:31+02:00" level=debug msg="requested aes key for file 53cc3579e982576e87bd44db9052f914e1f74b55, gid: 1YqJSpIxdavjQ8BxAttU0r" May 02 23:58:31 volumior volumio[1138]: 0+0 records in May 02 23:58:31 volumior volumio[1138]: 0+0 records out May 02 23:58:31 volumior volumio[1138]: 0 bytes copied, 0.000100771 s, 0.0 kB/s May 02 23:58:31 volumior go-librespot[1412]: time="2025-05-02T23:58:31+02:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:1YqJSpIxdavjQ8BxAttU0r: failed retrieving audio key: failed retrieving aes key with code 1" May 02 23:58:31 volumior volumio[1138]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error May 02 23:58:31 volumior volumio[1138]: 0+0 records in May 02 23:58:31 volumior volumio[1138]: 0+0 records out May 02 23:58:31 volumior volumio[1138]: 0 bytes copied, 9.7938e-05 s, 0.0 kB/s May 02 23:58:32 volumior volumio[1138]: 0+0 records in May 02 23:58:32 volumior volumio[1138]: 0+0 records out May 02 23:58:32 volumior volumio[1138]: 0 bytes copied, 9.953e-05 s, 0.0 kB/s May 02 23:58:32 volumior volumio[1138]: 0+0 records in May 02 23:58:32 volumior volumio[1138]: 0+0 records out May 02 23:58:32 volumior volumio[1138]: 0 bytes copied, 9.6882e-05 s, 0.0 kB/s May 02 23:58:33 volumior volumio[1138]: 0+0 records in May 02 23:58:33 volumior volumio[1138]: 0+0 records out May 02 23:58:33 volumior volumio[1138]: 0 bytes copied, 9.766e-05 s, 0.0 kB/s May 02 23:58:33 volumior volumio[1138]: 0+0 records in May 02 23:58:33 volumior volumio[1138]: 0+0 records out May 02 23:58:33 volumior volumio[1138]: 0 bytes copied, 9.7956e-05 s, 0.0 kB/s May 02 23:58:34 volumior volumio[1138]: 0+0 records in May 02 23:58:34 volumior volumio[1138]: 0+0 records out May 02 23:58:34 volumior volumio[1138]: 0 bytes copied, 0.000100197 s, 0.0 kB/s May 02 23:58:34 volumior volumio[1138]: 0+0 records in May 02 23:58:34 volumior volumio[1138]: 0+0 records out May 02 23:58:34 volumior volumio[1138]: 0 bytes copied, 0.000115882 s, 0.0 kB/s May 02 23:58:35 volumior volumio[1138]: 0+0 records in May 02 23:58:35 volumior volumio[1138]: 0+0 records out May 02 23:58:35 volumior volumio[1138]: 0 bytes copied, 9.8457e-05 s, 0.0 kB/s May 02 23:58:35 volumior volumio[1138]: 0+0 records in May 02 23:58:35 volumior volumio[1138]: 0+0 records out May 02 23:58:35 volumior volumio[1138]: 0 bytes copied, 0.000114568 s, 0.0 kB/s May 02 23:58:36 volumior volumio[1138]: 0+0 records in May 02 23:58:36 volumior volumio[1138]: 0+0 records out May 02 23:58:36 volumior volumio[1138]: 0 bytes copied, 0.000113179 s, 0.0 kB/s May 02 23:58:36 volumior volumio[1138]: 0+0 records in May 02 23:58:36 volumior volumio[1138]: 0+0 records out May 02 23:58:36 volumior volumio[1138]: 0 bytes copied, 0.000115197 s, 0.0 kB/s May 02 23:58:37 volumior volumio[1138]: 0+0 records in May 02 23:58:37 volumior volumio[1138]: 0+0 records out May 02 23:58:37 volumior volumio[1138]: 0 bytes copied, 0.000100365 s, 0.0 kB/s May 02 23:58:37 volumior volumio[1138]: 0+0 records in May 02 23:58:37 volumior volumio[1138]: 0+0 records out May 02 23:58:37 volumior volumio[1138]: 0 bytes copied, 9.8625e-05 s, 0.0 kB/s May 02 23:58:38 volumior volumio[1138]: 0+0 records in May 02 23:58:38 volumior volumio[1138]: 0+0 records out May 02 23:58:38 volumior volumio[1138]: 0 bytes copied, 9.8976e-05 s, 0.0 kB/s May 02 23:58:38 volumior volumio[1138]: 0+0 records in May 02 23:58:38 volumior volumio[1138]: 0+0 records out May 02 23:58:38 volumior volumio[1138]: 0 bytes copied, 0.000110549 s, 0.0 kB/s May 02 23:58:39 volumior volumio[1138]: 0+0 records in May 02 23:58:39 volumior volumio[1138]: 0+0 records out May 02 23:58:39 volumior volumio[1138]: 0 bytes copied, 9.7958e-05 s, 0.0 kB/s May 02 23:58:39 volumior volumio[1138]: 0+0 records in May 02 23:58:39 volumior volumio[1138]: 0+0 records out May 02 23:58:39 volumior volumio[1138]: 0 bytes copied, 9.9643e-05 s, 0.0 kB/s May 02 23:58:39 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 02 23:58:39 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 02 23:58:39 volumior volumio[1138]: info: Discovery: Getting this device information May 02 23:58:39 volumior volumio[1138]: info: CoreCommandRouter::volumioGetState May 02 23:58:39 volumior volumio[1138]: info: CorePlayQueue::getTrack 0 May 02 23:58:39 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 02 23:58:40 volumior volumio[1138]: 0+0 records in May 02 23:58:40 volumior volumio[1138]: 0+0 records out May 02 23:58:40 volumior volumio[1138]: 0 bytes copied, 0.000114365 s, 0.0 kB/s May 02 23:58:41 volumior volumio[1138]: 0+0 records in May 02 23:58:41 volumior volumio[1138]: 0+0 records out May 02 23:58:41 volumior volumio[1138]: 0 bytes copied, 9.8606e-05 s, 0.0 kB/s May 02 23:58:41 volumior volumio[1138]: 0+0 records in May 02 23:58:41 volumior volumio[1138]: 0+0 records out May 02 23:58:41 volumior volumio[1138]: 0 bytes copied, 0.000114087 s, 0.0 kB/s May 02 23:58:42 volumior volumio[1138]: 0+0 records in May 02 23:58:42 volumior volumio[1138]: 0+0 records out May 02 23:58:42 volumior volumio[1138]: 0 bytes copied, 0.000101403 s, 0.0 kB/s May 02 23:58:42 volumior volumio[1138]: 0+0 records in May 02 23:58:42 volumior volumio[1138]: 0+0 records out May 02 23:58:42 volumior volumio[1138]: 0 bytes copied, 9.7865e-05 s, 0.0 kB/s May 02 23:58:43 volumior volumio[1138]: 0+0 records in May 02 23:58:43 volumior volumio[1138]: 0+0 records out May 02 23:58:43 volumior volumio[1138]: 0 bytes copied, 0.000106755 s, 0.0 kB/s May 02 23:58:43 volumior volumio[1138]: 0+0 records in May 02 23:58:43 volumior volumio[1138]: 0+0 records out May 02 23:58:43 volumior volumio[1138]: 0 bytes copied, 0.000100199 s, 0.0 kB/s May 02 23:58:44 volumior volumio[1138]: 0+0 records in May 02 23:58:44 volumior volumio[1138]: 0+0 records out May 02 23:58:44 volumior volumio[1138]: 0 bytes copied, 0.000101125 s, 0.0 kB/s May 02 23:58:44 volumior volumio[1138]: 0+0 records in May 02 23:58:44 volumior volumio[1138]: 0+0 records out May 02 23:58:44 volumior volumio[1138]: 0 bytes copied, 9.8755e-05 s, 0.0 kB/s May 02 23:58:45 volumior volumio[1138]: 0+0 records in May 02 23:58:45 volumior volumio[1138]: 0+0 records out May 02 23:58:45 volumior volumio[1138]: 0 bytes copied, 9.981e-05 s, 0.0 kB/s May 02 23:58:45 volumior go-librespot[1412]: time="2025-05-02T23:58:45+02:00" level=trace msg="sent dealer ping" May 02 23:58:45 volumior go-librespot[1412]: time="2025-05-02T23:58:45+02:00" level=trace msg="received dealer pong" May 02 23:58:45 volumior volumio[1138]: 0+0 records in May 02 23:58:45 volumior volumio[1138]: 0+0 records out May 02 23:58:45 volumior volumio[1138]: 0 bytes copied, 9.9773e-05 s, 0.0 kB/s May 02 23:58:46 volumior volumio[1138]: 0+0 records in May 02 23:58:46 volumior volumio[1138]: 0+0 records out May 02 23:58:46 volumior volumio[1138]: 0 bytes copied, 0.000107791 s, 0.0 kB/s May 02 23:58:46 volumior volumio[1138]: 0+0 records in May 02 23:58:46 volumior volumio[1138]: 0+0 records out May 02 23:58:46 volumior volumio[1138]: 0 bytes copied, 0.000116754 s, 0.0 kB/s May 02 23:58:47 volumior volumio[1138]: 0+0 records in May 02 23:58:47 volumior volumio[1138]: 0+0 records out May 02 23:58:47 volumior volumio[1138]: 0 bytes copied, 9.9755e-05 s, 0.0 kB/s May 02 23:58:47 volumior volumio[1138]: 0+0 records in May 02 23:58:47 volumior volumio[1138]: 0+0 records out May 02 23:58:47 volumior volumio[1138]: 0 bytes copied, 0.000105162 s, 0.0 kB/s May 02 23:58:48 volumior volumio[1138]: 0+0 records in May 02 23:58:48 volumior volumio[1138]: 0+0 records out May 02 23:58:48 volumior volumio[1138]: 0 bytes copied, 0.000100125 s, 0.0 kB/s May 02 23:58:49 volumior volumio[1138]: 0+0 records in May 02 23:58:49 volumior volumio[1138]: 0+0 records out May 02 23:58:49 volumior volumio[1138]: 0 bytes copied, 0.000100441 s, 0.0 kB/s May 02 23:58:49 volumior volumio[1138]: 0+0 records in May 02 23:58:49 volumior volumio[1138]: 0+0 records out May 02 23:58:49 volumior volumio[1138]: 0 bytes copied, 9.9033e-05 s, 0.0 kB/s May 02 23:58:49 volumior volumio[1138]: info: CoreCommandRouter::executeOnPlugin: multiroom , audioOutputPlay May 02 23:58:49 volumior volumio[1138]: info: Error : CoreCommandRouter::executeOnPlugin: No method [audioOutputPlay] in plugin multiroom May 02 23:58:49 volumior volumio[1138]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 02 23:58:49 volumior volumio[1138]: TypeError: Cannot read property 'then' of undefined May 02 23:58:49 volumior volumio[1138]: at outputs.audioOutputPlay (/volumio/app/plugins/audio_interface/outputs/index.js:367:9) May 02 23:58:49 volumior volumio[1138]: at CoreCommandRouter.audioOutputPlay (/volumio/app/index.js:2279:30) May 02 23:58:49 volumior volumio[1138]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1456:26) May 02 23:58:49 volumior volumio[1138]: at Socket.emit (events.js:315:20) May 02 23:58:49 volumior volumio[1138]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 May 02 23:58:49 volumior volumio[1138]: at processTicksAndRejections (internal/process/task_queues.js:75:11) May 02 23:58:49 volumior volumio[1138]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 02 23:58:50 volumior sudo[3028]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-02 23:57 May 02 23:58:50 volumior sudo[3028]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 24 Apr 2025 09:33:57 AM CEST" VOLUMIO_VERSION="3.804" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="354f95cf0a6c2cbcd57b1aca3179c81c"