-- Logs begin at Sat 2024-10-12 09:01:36 CST, end at Sat 2024-10-12 09:03:32 CST. -- Oct 12 09:02:00 volumio systemd[1]: soundcard-init.service: Succeeded. Oct 12 09:02:00 volumio nmbd[854]: [2024/10/12 09:02:00.489354, 0] ../lib/util/become_daemon.c:138(daemon_ready) Oct 12 09:02:00 volumio nmbd[854]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Oct 12 09:02:00 volumio systemd[1]: Started Samba NMB Daemon. Oct 12 09:02:00 volumio systemd[1]: Starting Samba Winbind Daemon... Oct 12 09:02:01 volumio winbindd[1192]: [2024/10/12 09:02:01.262677, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Oct 12 09:02:01 volumio winbindd[1192]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Oct 12 09:02:01 volumio winbindd[1192]: [2024/10/12 09:02:01.288287, 0] ../lib/util/become_daemon.c:138(daemon_ready) Oct 12 09:02:01 volumio winbindd[1192]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Oct 12 09:02:01 volumio systemd[1]: Started Samba Winbind Daemon. Oct 12 09:02:01 volumio systemd[1]: Starting Samba SMB Daemon... Oct 12 09:02:02 volumio systemd[1]: Started Samba SMB Daemon. Oct 12 09:02:02 volumio smbd[1197]: [2024/10/12 09:02:02.356648, 0] ../lib/util/become_daemon.c:138(daemon_ready) Oct 12 09:02:02 volumio systemd[1]: Reached target Multi-User System. Oct 12 09:02:02 volumio smbd[1197]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Oct 12 09:02:02 volumio systemd[1]: Reached target Graphical Interface. Oct 12 09:02:02 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Oct 12 09:02:02 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Oct 12 09:02:02 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Oct 12 09:02:02 volumio systemd[1]: Startup finished in 31.175s (kernel) + 27.826s (userspace) = 59.002s. Oct 12 09:02:02 volumio volumio[1040]: info: ------------------------------------------- Oct 12 09:02:02 volumio volumio[1040]: info: ----- Volumio3 ---- Oct 12 09:02:02 volumio volumio[1040]: info: ------------------------------------------- Oct 12 09:02:02 volumio volumio[1040]: info: ----- System startup ---- Oct 12 09:02:02 volumio volumio[1040]: info: ------------------------------------------- Oct 12 09:02:03 volumio ntpd[1028]: Soliciting pool server 162.159.200.1 Oct 12 09:02:03 volumio ntpd[1028]: Soliciting pool server 185.209.85.222 Oct 12 09:02:03 volumio ntpd[1028]: Soliciting pool server 84.16.73.33 Oct 12 09:02:04 volumio ntpd[1028]: Soliciting pool server 108.59.2.24 Oct 12 09:02:04 volumio ntpd[1028]: Soliciting pool server 193.182.111.12 Oct 12 09:02:04 volumio ntpd[1028]: Soliciting pool server 162.159.200.123 Oct 12 09:02:05 volumio ntpd[1028]: Soliciting pool server 111.230.189.174 Oct 12 09:02:05 volumio ntpd[1028]: Soliciting pool server 119.28.206.193 Oct 12 09:02:05 volumio ntpd[1028]: Soliciting pool server 202.112.29.82 Oct 12 09:02:05 volumio volumio[1040]: info: MYVOLUMIO Environment detected Oct 12 09:02:05 volumio volumio-remote-updater[712]: [2024-10-12 09:02:05] [connect] Successful connection Oct 12 09:02:05 volumio volumio[1040]: info: Plugin folders cleanup Oct 12 09:02:05 volumio volumio[1040]: info: Scanning into folder /volumio/app/plugins/ Oct 12 09:02:05 volumio volumio[1040]: info: Scanning category audio_interface Oct 12 09:02:05 volumio volumio[1040]: info: Scanning category miscellanea Oct 12 09:02:05 volumio volumio[1040]: info: Scanning category music_service Oct 12 09:02:05 volumio volumio[1040]: info: Scanning category plugins.json Oct 12 09:02:05 volumio volumio[1040]: info: Scanning category system_controller Oct 12 09:02:05 volumio volumio[1040]: info: Scanning category user_interface Oct 12 09:02:05 volumio volumio[1040]: info: Scanning into folder /data/plugins/ Oct 12 09:02:05 volumio volumio[1040]: info: Scanning category user_interface Oct 12 09:02:05 volumio volumio[1040]: info: Plugin folders cleanup completed Oct 12 09:02:05 volumio volumio[1040]: info: ------------------------------------------- Oct 12 09:02:05 volumio volumio[1040]: info: ----- Core plugins startup ---- Oct 12 09:02:05 volumio volumio[1040]: info: ------------------------------------------- Oct 12 09:02:05 volumio volumio[1040]: info: Loading plugins from folder /volumio/app/plugins/ Oct 12 09:02:05 volumio volumio[1040]: info: Adding plugin upnp to MyMusic Plugins Oct 12 09:02:05 volumio volumio[1040]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 12 09:02:05 volumio volumio[1040]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 12 09:02:05 volumio volumio[1040]: info: Loading plugins from folder /data/plugins/ Oct 12 09:02:05 volumio volumio[1040]: info: Loading plugin "system"... Oct 12 09:02:06 volumio volumio[1040]: info: Loading plugin "appearance"... Oct 12 09:02:06 volumio ntpd[1028]: Soliciting pool server 116.203.151.74 Oct 12 09:02:06 volumio ntpd[1028]: Soliciting pool server 193.182.111.142 Oct 12 09:02:06 volumio ntpd[1028]: Soliciting pool server 84.16.67.12 Oct 12 09:02:07 volumio ntpd[1028]: Soliciting pool server 139.199.215.251 Oct 12 09:02:09 volumio volumio[1040]: info: Loading plugin "network"... Oct 12 09:02:09 volumio volumio[1040]: info: Refreshing Cached IP Addresses Oct 12 09:02:09 volumio sudo[1288]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 09:02:09 volumio sudo[1288]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 09:02:09 volumio sudo[1288]: pam_unix(sudo:session): session closed for user root Oct 12 09:02:09 volumio volumio[1040]: info: Loading plugin "services"... Oct 12 09:02:09 volumio volumio[1040]: info: Loading plugin "alsa_controller"... Oct 12 09:02:09 volumio sudo[1290]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 09:02:09 volumio sudo[1290]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 09:02:09 volumio sudo[1293]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 12 09:02:09 volumio sudo[1293]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 09:02:09 volumio sudo[1290]: pam_unix(sudo:session): session closed for user root Oct 12 09:02:10 volumio volumio[1040]: warn: Unable to locate the audio output device USB PnP Sound Device. Please configure a valid output device. Oct 12 09:02:10 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 09:02:10 volumio volumio[1040]: info: Loading plugin "wizard"... Oct 12 09:02:10 volumio volumio[1040]: info: Loading plugin "networkfs"... Oct 12 09:02:10 volumio volumio[1040]: info: Starting Udev Watcher for removable devices Oct 12 09:02:10 volumio volumio[1040]: info: Ignoring mount for partition: boot Oct 12 09:02:10 volumio volumio[1040]: info: Ignoring mount for partition: volumio Oct 12 09:02:10 volumio volumio[1040]: info: Ignoring mount for partition: volumio_data Oct 12 09:02:10 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 09:02:10 volumio volumio[1040]: info: Loading plugin "volumio_command_line_client"... Oct 12 09:02:10 volumio sudo[1299]: 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.3.75/共享文件 /mnt/NAS/共享文件 Oct 12 09:02:10 volumio sudo[1299]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 09:02:10 volumio volumio[1040]: info: Loading plugin "upnp"... Oct 12 09:02:11 volumio volumio[1040]: info: [1728694931128] Starting Upmpd Daemon Oct 12 09:02:11 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 09:02:11 volumio volumio[1040]: info: Loading plugin "my_music"... Oct 12 09:02:11 volumio volumio[1040]: info: Loading plugin "mpd"... Oct 12 09:02:11 volumio kernel: FS-Cache: Loaded Oct 12 09:02:11 volumio kernel: Key type dns_resolver registered Oct 12 09:02:11 volumio kernel: Key type cifs.spnego registered Oct 12 09:02:11 volumio kernel: Key type cifs.idmap registered Oct 12 09:02:11 volumio 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. Oct 12 09:02:11 volumio kernel: CIFS: Attempting to mount //192.168.3.75/共享文件 Oct 12 09:02:11 volumio sudo[1299]: pam_unix(sudo:session): session closed for user root Oct 12 09:02:12 volumio systemd[1]: systemd-fsckd.service: Succeeded. Oct 12 09:02:12 volumio volumio[1040]: info: Loading plugin "upnp_browser"... Oct 12 09:02:12 volumio sh[623]: timed out Oct 12 09:02:12 volumio sh[623]: dhcpcd exited Oct 12 09:02:12 volumio dhcpcd[671]: timed out Oct 12 09:02:12 volumio sh[623]: ifup: failed to bring up eth0 Oct 12 09:02:12 volumio dhcpcd[671]: dhcpcd exited Oct 12 09:02:12 volumio systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Oct 12 09:02:12 volumio systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Oct 12 09:02:12 volumio sudo[1293]: pam_unix(sudo:session): session closed for user root Oct 12 09:02:13 volumio volumio[1040]: info: Loading plugin "alarm-clock"... Oct 12 09:02:13 volumio volumio[1040]: info: Loading plugin "airplay_emulation"... Oct 12 09:02:13 volumio volumio[1040]: info: Starting Shairport Sync Oct 12 09:02:13 volumio volumio[1040]: info: Loading plugin "last_100"... Oct 12 09:02:13 volumio volumio[1040]: info: Loading plugin "webradio"... Oct 12 09:02:14 volumio volumio[1040]: info: Loading plugin "i2s_dacs"... Oct 12 09:02:14 volumio volumio[1040]: info: I2S DAC not set, start Auto-detection Oct 12 09:02:14 volumio volumio[1040]: info: Loading plugin "volumiodiscovery"... Oct 12 09:02:14 volumio volumio[1040]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 12 09:02:14 volumio volumio[1040]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 09:02:14 volumio volumio[1040]: *** WARNING *** For more information see Oct 12 09:02:14 volumio volumio[1040]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 12 09:02:14 volumio volumio[1040]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 09:02:14 volumio volumio[1040]: *** WARNING *** For more information see Oct 12 09:02:14 volumio node[1040]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 12 09:02:14 volumio node[1040]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 09:02:14 volumio node[1040]: *** WARNING *** For more information see Oct 12 09:02:14 volumio node[1040]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 12 09:02:14 volumio node[1040]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 09:02:14 volumio node[1040]: *** WARNING *** For more information see Oct 12 09:02:14 volumio volumio[1040]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 12 09:02:14 volumio volumio[1040]: info: Discovery: Started advertising with name: Volumio Oct 12 09:02:14 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 09:02:14 volumio volumio[1040]: info: Loading plugin "peppy_screensaver"... Oct 12 09:02:15 volumio systemd[1]: systemd-hostnamed.service: Succeeded. Oct 12 09:02:15 volumio volumio[1040]: info: Applying required configuration parameters for plugin peppy_screensaver Oct 12 09:02:15 volumio volumio[1040]: info: Loading plugin "outputs"... Oct 12 09:02:15 volumio volumio[1040]: info: Loading plugin "albumart"... Oct 12 09:02:15 volumio volumio[1040]: info: Plugin example_plugin is not enabled Oct 12 09:02:15 volumio volumio[1040]: info: Loading plugin "inputs"... Oct 12 09:02:15 volumio volumio[1040]: info: Loading plugin "updater_comm"... Oct 12 09:02:16 volumio volumio[1040]: Forking 1 albumart workers Oct 12 09:02:16 volumio volumio[1040]: info: Plugin mpdemulation is not enabled Oct 12 09:02:16 volumio volumio[1040]: info: Loading plugin "rest_api"... Oct 12 09:02:16 volumio volumio[1040]: info: Loading plugin "websocket"... Oct 12 09:02:16 volumio volumio[1040]: info: Starting Socket.io Server version 2.3.0 Oct 12 09:02:16 volumio volumio[1040]: info: Loading i18n strings for locale zh Oct 12 09:02:16 volumio volumio[1040]: Updating browse sources language Oct 12 09:02:16 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 09:02:17 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 09:02:17 volumio volumio[1040]: Starting albumart workers Oct 12 09:02:17 volumio volumio[1040]: info: CoreCommandRouter::initPlayerControls Oct 12 09:02:17 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:17 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:17 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 09:02:17 volumio volumio[1040]: Express server listening on port 3000 Oct 12 09:02:17 volumio volumio[1040]: [Metrics] WebUI: 16s 450.80ms Oct 12 09:02:18 volumio volumio[1040]: info: Setting Device type: x86 Oct 12 09:02:18 volumio volumio[1040]: info: CoreStateMachine::resetVolumioState Oct 12 09:02:18 volumio volumio[1040]: info: CoreStateMachine::getcurrentVolume Oct 12 09:02:18 volumio volumio[1040]: info: CoreCommandRouter::volumioRetrievevolume Oct 12 09:02:18 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 09:02:18 volumio volumio[1040]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Oct 12 09:02:18 volumio volumio[1040]: info: Completed loading Core Plugins Oct 12 09:02:18 volumio volumio[1040]: info: Preparing to generate the ALSA configuration file Oct 12 09:02:18 volumio volumio[1040]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Oct 12 09:02:18 volumio volumio[1040]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Oct 12 09:02:18 volumio volumio[1040]: info: The plugin peppy_screensaver has an ALSA contribution file Peppyalsa.postPeppyalsa.5.conf Oct 12 09:02:18 volumio volumio[1040]: info: Reading ALSA contributions from plugins. Oct 12 09:02:18 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:18 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:18 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 09:02:18 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:18 volumio volumio[1040]: info: CoreStateMachine::updateTrackBlock Oct 12 09:02:18 volumio volumio[1040]: info: CorePlayQueue::getTrackBlock Oct 12 09:02:18 volumio volumio[1040]: info: CoreCommandRouter::volumioRetrievevolume Oct 12 09:02:18 volumio volumio[1040]: info: CoreCommandRouter::volumioGetState Oct 12 09:02:18 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:18 volumio volumio[1040]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Oct 12 09:02:18 volumio volumio[1040]: info: Reloading queue from file Oct 12 09:02:19 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:19 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:19 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 09:02:19 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:19 volumio volumio[1040]: info: CoreStateMachine::setRepeat true single undefined Oct 12 09:02:19 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:19 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:19 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 09:02:19 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:19 volumio volumio[1040]: info: CoreStateMachine::setRandom false Oct 12 09:02:19 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:19 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:19 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 09:02:19 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:19 volumio volumio[1040]: info: Asound.conf file unchanged, so no further update is needed Oct 12 09:02:19 volumio volumio[1040]: info: Output device has changed, restarting MPD Oct 12 09:02:19 volumio sudo[1443]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 12 09:02:19 volumio volumio[1040]: info: Output device has changed, restarting Shairport Sync Oct 12 09:02:19 volumio sudo[1443]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 09:02:19 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:19 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 09:02:19 volumio sudo[1443]: pam_unix(sudo:session): session closed for user root Oct 12 09:02:19 volumio sudo[1445]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 12 09:02:19 volumio sudo[1445]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 09:02:19 volumio systemd[1]: Listening on mpd.socket. Oct 12 09:02:19 volumio systemd[1]: Starting Music Player Daemon... Oct 12 09:02:19 volumio volumio[1040]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 09:02:19 volumio volumio[1040]: info: ___________ START PLUGINS ___________ Oct 12 09:02:19 volumio volumio[1040]: info: ControllerMpd::onStart: Initializing MPD Oct 12 09:02:19 volumio volumio[1040]: info: Creating MPD Configuration file Oct 12 09:02:19 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 09:02:19 volumio volumio[1040]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 09:02:19 volumio sudo[1453]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 12 09:02:19 volumio volumio[1040]: info: [1728694939557] CoreMusicLibrary::Adding element 媒体服务器 Oct 12 09:02:19 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 09:02:19 volumio sudo[1453]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 09:02:19 volumio sudo[1453]: pam_unix(sudo:session): session closed for user root Oct 12 09:02:19 volumio sudo[1455]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 12 09:02:19 volumio sudo[1455]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 09:02:19 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:19 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 09:02:19 volumio sudo[1451]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 12 09:02:19 volumio sudo[1451]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 09:02:19 volumio sudo[1451]: pam_unix(sudo:session): session closed for user root Oct 12 09:02:19 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Oct 12 09:02:19 volumio systemd[1]: mpd.service: Succeeded. Oct 12 09:02:19 volumio systemd[1]: Stopped Music Player Daemon. Oct 12 09:02:19 volumio systemd[1]: Starting Music Player Daemon... Oct 12 09:02:19 volumio volumio[1040]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 09:02:19 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:19 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 09:02:19 volumio volumio[1040]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 09:02:19 volumio volumio[1040]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 09:02:19 volumio volumio[1040]: info: [1728694939770] CoreMusicLibrary::Adding element Last_100 Oct 12 09:02:19 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 09:02:19 volumio volumio[1040]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 09:02:19 volumio volumio[1040]: info: [1728694939775] CoreMusicLibrary::Adding element Webradio Oct 12 09:02:19 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 09:02:19 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 09:02:19 volumio volumio[1040]: info: Initializing BBC Radios Oct 12 09:02:19 volumio sudo[1462]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 12 09:02:19 volumio sudo[1462]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 09:02:19 volumio sudo[1462]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Oct 12 09:02:19 volumio sudo[1462]: pam_unix(sudo:session): session closed for user root Oct 12 09:02:19 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 09:02:19 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 09:02:19 volumio volumio[1040]: info: Loading i18n strings for locale zh Oct 12 09:02:19 volumio volumio[1040]: info: /tmp/myfifo created Oct 12 09:02:19 volumio volumio[1040]: info: /tmp/myfifosa created Oct 12 09:02:20 volumio sudo[1483]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/modprobe snd-dummy index=7 pcm_substreams=1 fake_buffer=0 Oct 12 09:02:20 volumio sudo[1483]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 09:02:20 volumio sudo[1483]: pam_unix(sudo:session): session closed for user root Oct 12 09:02:20 volumio volumio[1040]: info: snd-dummy loaded Oct 12 09:02:20 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 09:02:20 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:20 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , startShairportSync Oct 12 09:02:20 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:20 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 09:02:20 volumio sudo[1504]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount --bind /tmp/shairport-sync.conf.tmpl /volumio/app/plugins/music_service/airplay_emulation/shairport-sync.conf.tmpl Oct 12 09:02:20 volumio sudo[1504]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 09:02:20 volumio sudo[1504]: pam_unix(sudo:session): session closed for user root Oct 12 09:02:20 volumio volumio[1040]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 09:02:20 volumio volumio[1040]: info: Volumio Calling Home Oct 12 09:02:20 volumio volumio[1040]: info: Discovery: adding 492524ff-0d18-4e9b-b0b7-e00a3046faf7 Oct 12 09:02:20 volumio volumio[1040]: info: Discovery: Found device Volumio Oct 12 09:02:20 volumio volumio[1040]: info: CoreCommandRouter::volumioGetState Oct 12 09:02:20 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:21 volumio volumio[1040]: info: MPD Permissions set Oct 12 09:02:21 volumio volumio[1040]: info: MPD Permissions set Oct 12 09:02:21 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 09:02:21 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 09:02:21 volumio volumio[1040]: info: Discovery: Getting this device information Oct 12 09:02:21 volumio volumio[1040]: info: CoreCommandRouter::volumioGetState Oct 12 09:02:21 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:21 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 09:02:21 volumio volumio[1040]: info: CoreCommandRouter::volumioGetState Oct 12 09:02:21 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:21 volumio volumio[1040]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Oct 12 09:02:21 volumio sudo[1512]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 09:02:21 volumio sudo[1512]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 09:02:21 volumio sudo[1512]: pam_unix(sudo:session): session closed for user root Oct 12 09:02:21 volumio volumio-remote-updater[712]: [2024-10-12 09:02:21] [connect] Successful connection Oct 12 09:02:21 volumio sudo[1515]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 09:02:21 volumio sudo[1515]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 09:02:21 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:21 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:21 volumio sudo[1515]: pam_unix(sudo:session): session closed for user root Oct 12 09:02:21 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:21 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:21 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:21 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:21 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:21 volumio sudo[1521]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount --bind /tmp/mpd.conf.tmpl /volumio/app/plugins/music_service/mpd/mpd.conf.tmpl Oct 12 09:02:21 volumio sudo[1521]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 09:02:21 volumio sudo[1521]: pam_unix(sudo:session): session closed for user root Oct 12 09:02:21 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 09:02:21 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 12 09:02:21 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:21 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:21 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:21 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:21 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:21 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:21 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:21 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:21 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:22 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 09:02:22 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 12 09:02:22 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:22 volumio volumio[1040]: verbose: New Socket.io Connection to 192.168.3.77 from 192.168.3.27 UA: okhttp/4.9.2 Engine version: 3 Transport: websocket Total Clients: 3 Oct 12 09:02:22 volumio volumio-remote-updater[712]: [2024-10-12 09:02:22] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1728694941 101 Oct 12 09:02:22 volumio volumio[1040]: 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: 4 Oct 12 09:02:22 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , createMPDFile Oct 12 09:02:22 volumio sudo[1536]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 12 09:02:22 volumio sudo[1536]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 09:02:22 volumio volumio[1040]: info: Starting Shairport Sync Oct 12 09:02:22 volumio sudo[1536]: pam_unix(sudo:session): session closed for user root Oct 12 09:02:22 volumio volumio[1040]: info: Starting Shairport Sync Oct 12 09:02:22 volumio volumio[1040]: info: Starting Shairport Sync Oct 12 09:02:22 volumio sudo[1539]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 12 09:02:22 volumio sudo[1539]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 09:02:22 volumio sudo[1541]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 12 09:02:22 volumio volumio[1040]: info: Starting Shairport Sync Oct 12 09:02:22 volumio sudo[1541]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 09:02:22 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 12 09:02:22 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 12 09:02:22 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 12 09:02:22 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 12 09:02:23 volumio sudo[1539]: pam_unix(sudo:session): session closed for user root Oct 12 09:02:23 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 12 09:02:23 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Oct 12 09:02:23 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 12 09:02:23 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 12 09:02:23 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 12 09:02:23 volumio sudo[1541]: pam_unix(sudo:session): session closed for user root Oct 12 09:02:23 volumio sudo[1544]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 12 09:02:23 volumio sudo[1544]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 09:02:23 volumio volumio[1040]: info: CoreCommandRouter::volumioGetState Oct 12 09:02:23 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:23 volumio sudo[1548]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 12 09:02:23 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Oct 12 09:02:23 volumio sudo[1548]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 09:02:23 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 12 09:02:23 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 12 09:02:23 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 12 09:02:23 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 12 09:02:23 volumio sudo[1544]: pam_unix(sudo:session): session closed for user root Oct 12 09:02:23 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 12 09:02:23 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Oct 12 09:02:23 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 12 09:02:23 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 12 09:02:23 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 12 09:02:23 volumio sudo[1548]: pam_unix(sudo:session): session closed for user root Oct 12 09:02:23 volumio sudo[1556]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 12 09:02:23 volumio sudo[1556]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 09:02:23 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Oct 12 09:02:23 volumio systemd[1]: mpd.service: Succeeded. Oct 12 09:02:23 volumio systemd[1]: Stopped Music Player Daemon. Oct 12 09:02:23 volumio systemd[1]: Starting Music Player Daemon... Oct 12 09:02:23 volumio volumio[1040]: info: Shairport-Sync Started Oct 12 09:02:23 volumio volumio[1040]: Error adding Membership: Error: addMembership EINVAL Oct 12 09:02:23 volumio volumio[1040]: info: Shairport-Sync Started Oct 12 09:02:23 volumio volumio[1040]: info: Shairport-Sync Started Oct 12 09:02:23 volumio volumio[1040]: info: MPD Permissions set Oct 12 09:02:23 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:23 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:23 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:23 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:23 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:23 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:23 volumio sudo[1561]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 12 09:02:23 volumio sudo[1561]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 09:02:23 volumio sudo[1561]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Oct 12 09:02:23 volumio sudo[1561]: pam_unix(sudo:session): session closed for user root Oct 12 09:02:23 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 09:02:23 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 12 09:02:23 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:24 volumio volumio[1040]: verbose: New Socket.io Connection to 192.168.3.77 from 192.168.3.27 UA: okhttp/4.9.2 Engine version: 3 Transport: websocket Total Clients: 5 Oct 12 09:02:24 volumio volumio[1040]: info: Shairport-Sync Started Oct 12 09:02:24 volumio volumio[1040]: info: CoreCommandRouter::volumioGetState Oct 12 09:02:24 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:24 volumio sudo[1571]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 12 09:02:24 volumio sudo[1571]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 09:02:24 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 12 09:02:24 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 12 09:02:24 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Oct 12 09:02:24 volumio sudo[1571]: pam_unix(sudo:session): session closed for user root Oct 12 09:02:24 volumio volumio[1040]: info: Upmpdcli Daemon Started Oct 12 09:02:24 volumio volumio[1040]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Celine%20Dion/29f85334-bc57-4ba2-b5c3-0d4ec376b6cc.jpg' Oct 12 09:02:26 volumio volumio[1040]: info: Volumio called home Oct 12 09:02:27 volumio mpd[1564]: Oct 12 09:02 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 12 09:02:27 volumio volumio[1040]: Upnp client error: Error: This socket has been ended by the other party Oct 12 09:02:27 volumio systemd[1]: Started Music Player Daemon. Oct 12 09:02:27 volumio sudo[1455]: pam_unix(sudo:session): session closed for user root Oct 12 09:02:27 volumio sudo[1556]: pam_unix(sudo:session): session closed for user root Oct 12 09:02:27 volumio sudo[1445]: pam_unix(sudo:session): session closed for user root Oct 12 09:02:27 volumio volumio[1040]: info: Completed starting Core Plugins Oct 12 09:02:27 volumio volumio[1040]: info: ------------------------------------------- Oct 12 09:02:27 volumio volumio[1040]: info: ----- MyVolumio plugins startup ---- Oct 12 09:02:27 volumio volumio[1040]: info: ------------------------------------------- Oct 12 09:02:27 volumio volumio[1040]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 12 09:02:27 volumio volumio[1040]: error: MPD error: The expression evaluated to a falsy value: Oct 12 09:02:27 volumio volumio[1040]: assert.ok(self.idling) Oct 12 09:02:27 volumio volumio[1040]: error: The expression evaluated to a falsy value: Oct 12 09:02:27 volumio volumio[1040]: assert.ok(self.idling) Oct 12 09:02:27 volumio volumio[1040]: info: MPD running with PID1564 Oct 12 09:02:27 volumio volumio[1040]: ,establishing connection Oct 12 09:02:27 volumio volumio[1040]: error: MPD error: The expression evaluated to a falsy value: Oct 12 09:02:27 volumio volumio[1040]: assert.ok(self.idling) Oct 12 09:02:27 volumio volumio[1040]: error: The expression evaluated to a falsy value: Oct 12 09:02:27 volumio volumio[1040]: assert.ok(self.idling) Oct 12 09:02:27 volumio volumio[1040]: error: MPD error: The expression evaluated to a falsy value: Oct 12 09:02:27 volumio volumio[1040]: assert.ok(self.idling) Oct 12 09:02:27 volumio volumio[1040]: error: The expression evaluated to a falsy value: Oct 12 09:02:27 volumio volumio[1040]: assert.ok(self.idling) Oct 12 09:02:27 volumio volumio[1040]: error: updateQueue error: null Oct 12 09:02:28 volumio volumio[1040]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Oct 12 09:02:28 volumio volumio[1573]: Generating RSA private key, 4096 bit long modulus (2 primes) Oct 12 09:02:29 volumio volumio[1573]: ........................++++ Oct 12 09:02:29 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 12 09:02:29 volumio volumio[1040]: info: CoreCommandRouter::volumioGetState Oct 12 09:02:29 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:30 volumio volumio[1040]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Celine%20Dion/29f85334-bc57-4ba2-b5c3-0d4ec376b6cc.jpg' Oct 12 09:02:30 volumio volumio[1040]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Celine%20Dion/29f85334-bc57-4ba2-b5c3-0d4ec376b6cc.jpg' Oct 12 09:02:31 volumio volumio[1040]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Oct 12 09:02:32 volumio sudo[1780]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 09:02:32 volumio sudo[1780]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 09:02:32 volumio sudo[1780]: pam_unix(sudo:session): session closed for user root Oct 12 09:02:32 volumio sudo[1782]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 09:02:32 volumio sudo[1782]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 09:02:32 volumio sudo[1782]: pam_unix(sudo:session): session closed for user root Oct 12 09:02:32 volumio volumio[1573]: .......................................................++++ Oct 12 09:02:32 volumio volumio[1573]: e is 65537 (0x010001) Oct 12 09:02:32 volumio volumio[1573]: writing RSA key Oct 12 09:02:32 volumio volumio[1040]: verbose: New Socket.io Connection to 192.168.3.77 from 192.168.3.27 UA: okhttp/4.9.2 Engine version: 3 Transport: polling Total Clients: 8 Oct 12 09:02:33 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 12 09:02:33 volumio volumio[1040]: info: CoreCommandRouter::volumioGetVisibleSources Oct 12 09:02:33 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 09:02:33 volumio volumio[1040]: info: CoreCommandRouter::volumioGetState Oct 12 09:02:33 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:33 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 12 09:02:33 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 12 09:02:33 volumio volumio[1040]: info: Received Get System Info Oct 12 09:02:33 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 09:02:33 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 09:02:33 volumio volumio[1040]: info: Discovery: Getting this device information Oct 12 09:02:33 volumio volumio[1040]: info: CoreCommandRouter::volumioGetState Oct 12 09:02:33 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:33 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 09:02:33 volumio volumio[1040]: info: CoreCommandRouter::volumioGetState Oct 12 09:02:33 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:33 volumio volumio[1040]: info: Listing playlists Oct 12 09:02:33 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 12 09:02:33 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 12 09:02:33 volumio volumio[1040]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Celine%20Dion/29f85334-bc57-4ba2-b5c3-0d4ec376b6cc.jpg' Oct 12 09:02:33 volumio volumio[1040]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Celine%20Dion/29f85334-bc57-4ba2-b5c3-0d4ec376b6cc.jpg' Oct 12 09:02:33 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 12 09:02:33 volumio volumio[1040]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Celine%20Dion/29f85334-bc57-4ba2-b5c3-0d4ec376b6cc.jpg' Oct 12 09:02:33 volumio volumio[1040]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Celine%20Dion/29f85334-bc57-4ba2-b5c3-0d4ec376b6cc.jpg' Oct 12 09:02:33 volumio volumio[1040]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Celine%20Dion/29f85334-bc57-4ba2-b5c3-0d4ec376b6cc.jpg' Oct 12 09:02:34 volumio volumio[1040]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Celine%20Dion/29f85334-bc57-4ba2-b5c3-0d4ec376b6cc.jpg' Oct 12 09:02:34 volumio volumio[1040]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Celine%20Dion/29f85334-bc57-4ba2-b5c3-0d4ec376b6cc.jpg' Oct 12 09:02:34 volumio volumio[1040]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Celine%20Dion/29f85334-bc57-4ba2-b5c3-0d4ec376b6cc.jpg' Oct 12 09:02:34 volumio volumio[1040]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Celine%20Dion/29f85334-bc57-4ba2-b5c3-0d4ec376b6cc.jpg' Oct 12 09:02:34 volumio volumio[1040]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Celine%20Dion/29f85334-bc57-4ba2-b5c3-0d4ec376b6cc.jpg' Oct 12 09:02:34 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 12 09:02:34 volumio volumio[1040]: info: Received Get System Info Oct 12 09:02:34 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 09:02:34 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 09:02:34 volumio volumio[1040]: info: Discovery: Getting this device information Oct 12 09:02:34 volumio volumio[1040]: info: CoreCommandRouter::volumioGetState Oct 12 09:02:34 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:34 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 09:02:34 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 12 09:02:34 volumio volumio[1040]: info: CoreCommandRouter::volumioGetQueue Oct 12 09:02:34 volumio volumio[1040]: info: CoreStateMachine::getQueue Oct 12 09:02:34 volumio volumio[1040]: info: CorePlayQueue::getQueue Oct 12 09:02:35 volumio volumio[1040]: info: CoreCommandRouter::volumioGetVisibleSources Oct 12 09:02:35 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 09:02:35 volumio volumio[1040]: info: CoreCommandRouter::volumioGetState Oct 12 09:02:35 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:35 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 12 09:02:35 volumio volumio[1040]: info: CoreCommandRouter::volumioGetQueue Oct 12 09:02:35 volumio volumio[1040]: info: CoreStateMachine::getQueue Oct 12 09:02:35 volumio volumio[1040]: info: CorePlayQueue::getQueue Oct 12 09:02:35 volumio volumio[1040]: info: Listing playlists Oct 12 09:02:35 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 12 09:02:35 volumio volumio[1040]: info: Received Get System Info Oct 12 09:02:35 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 09:02:35 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 09:02:35 volumio volumio[1040]: info: Discovery: Getting this device information Oct 12 09:02:35 volumio volumio[1040]: info: CoreCommandRouter::volumioGetState Oct 12 09:02:35 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:35 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 09:02:35 volumio volumio[1040]: info: CoreCommandRouter::volumioGetState Oct 12 09:02:35 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:35 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 12 09:02:35 volumio volumio[1040]: info: Received Get System Info Oct 12 09:02:35 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 09:02:35 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 09:02:35 volumio volumio[1040]: info: Discovery: Getting this device information Oct 12 09:02:35 volumio volumio[1040]: info: CoreCommandRouter::volumioGetState Oct 12 09:02:35 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:35 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 09:02:35 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 12 09:02:35 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 12 09:02:36 volumio volumio[1040]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Celine%20Dion/29f85334-bc57-4ba2-b5c3-0d4ec376b6cc.jpg' Oct 12 09:02:36 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 12 09:02:36 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 12 09:02:36 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 12 09:02:36 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 12 09:02:36 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 12 09:02:36 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 12 09:02:36 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 12 09:02:36 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 12 09:02:36 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 12 09:02:36 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 12 09:02:36 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 12 09:02:36 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 12 09:02:36 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 12 09:02:36 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 12 09:02:36 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 12 09:02:36 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 12 09:02:36 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 12 09:02:36 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 12 09:02:36 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 12 09:02:36 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 12 09:02:36 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 12 09:02:36 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 12 09:02:36 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 12 09:02:36 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 12 09:02:36 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 12 09:02:36 volumio volumio[1040]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 12 09:02:36 volumio volumio[1040]: info: Adding plugin bluetooth to MyMusic Plugins Oct 12 09:02:36 volumio volumio[1040]: info: Adding plugin multiroom to MyMusic Plugins Oct 12 09:02:36 volumio volumio[1040]: info: Adding plugin metavolumio to MyMusic Plugins Oct 12 09:02:36 volumio volumio[1040]: info: Adding plugin cd_controller to MyMusic Plugins Oct 12 09:02:36 volumio volumio[1040]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 12 09:02:36 volumio volumio[1040]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 12 09:02:36 volumio volumio[1040]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 12 09:02:39 volumio volumio[1040]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 12 09:02:39 volumio volumio[1040]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 12 09:02:39 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 09:02:39 volumio volumio[1040]: info: Starting MyVolumio Remote Streaming Endpoints Oct 12 09:02:39 volumio volumio[1040]: info: MyVolumio login type: Token Oct 12 09:02:39 volumio volumio[1040]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 12 09:02:39 volumio volumio[1040]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 12 09:02:41 volumio volumio[1040]: info: Starting Streaming Service Transparent Proxy Oct 12 09:02:41 volumio volumio[1040]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 12 09:02:41 volumio volumio[1040]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 12 09:02:41 volumio volumio[1040]: info: Streaming services startup Oct 12 09:02:41 volumio volumio[1040]: info: Starting Streaming Daemon Oct 12 09:02:41 volumio sudo[1808]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 12 09:02:41 volumio sudo[1808]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 09:02:41 volumio sudo[1808]: pam_unix(sudo:session): session closed for user root Oct 12 09:02:41 volumio volumio[1040]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 12 09:02:41 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 12 09:02:41 volumio volumio[1040]: info: CoreCommandRouter::volumioPlay Oct 12 09:02:41 volumio volumio[1040]: info: CoreStateMachine::play index undefined Oct 12 09:02:41 volumio volumio[1040]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 09:02:41 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:41 volumio volumio[1040]: info: CoreStateMachine::startPlaybackTimer Oct 12 09:02:41 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:41 volumio volumio[1040]: info: [1728694961818] ControllerUPNPBrowser::clearAddPlayTrack Oct 12 09:02:41 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand stop Oct 12 09:02:41 volumio volumio[1040]: error: Cannot start Volumio Streaming Daemon Oct 12 09:02:41 volumio volumio[1040]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 12 09:02:41 volumio volumio[1040]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 12 09:02:41 volumio volumio[1040]: info: sendMpdCommand stop took 64 milliseconds Oct 12 09:02:41 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand clear Oct 12 09:02:41 volumio volumio[1040]: info: Oct 12 09:02:41 volumio volumio[1040]: ---------------------------- MPD announces system playlist update Oct 12 09:02:41 volumio volumio[1040]: info: Ignoring MPD Status Update Oct 12 09:02:41 volumio volumio[1040]: info: sendMpdCommand clear took 21 milliseconds Oct 12 09:02:41 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.3.75:8200/MediaItems/142.dsd" Oct 12 09:02:41 volumio volumio[1040]: info: Oct 12 09:02:41 volumio volumio[1040]: ---------------------------- MPD announces system playlist update Oct 12 09:02:41 volumio volumio[1040]: info: Ignoring MPD Status Update Oct 12 09:02:41 volumio volumio[1040]: info: Oct 12 09:02:41 volumio volumio[1040]: ---------------------------- MPD announces system playlist update Oct 12 09:02:41 volumio volumio[1040]: info: Ignoring MPD Status Update Oct 12 09:02:41 volumio volumio[1040]: info: Oct 12 09:02:41 volumio volumio[1040]: ---------------------------- MPD announces system playlist update Oct 12 09:02:41 volumio volumio[1040]: info: Ignoring MPD Status Update Oct 12 09:02:41 volumio volumio[1040]: info: CoreCommandRouter::volumioGetState Oct 12 09:02:41 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:41 volumio volumio[1040]: error: updateQueue error: null Oct 12 09:02:41 volumio volumio[1040]: error: updateQueue error: null Oct 12 09:02:41 volumio volumio[1040]: error: updateQueue error: null Oct 12 09:02:41 volumio volumio[1040]: error: updateQueue error: null Oct 12 09:02:41 volumio volumio[1040]: info: ------------------------------ 62ms Oct 12 09:02:41 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.3.75:8200/MediaItems/142.dsd" Oct 12 09:02:41 volumio volumio[1040]: info: ------------------------------ 52ms Oct 12 09:02:41 volumio volumio[1040]: info: ------------------------------ 48ms Oct 12 09:02:41 volumio volumio[1040]: info: ------------------------------ 43ms Oct 12 09:02:41 volumio volumio[1040]: info: Oct 12 09:02:41 volumio volumio[1040]: ---------------------------- MPD announces system playlist update Oct 12 09:02:41 volumio volumio[1040]: info: Ignoring MPD Status Update Oct 12 09:02:41 volumio volumio[1040]: info: sendMpdCommand add "http://192.168.3.75:8200/MediaItems/142.dsd" took 19 milliseconds Oct 12 09:02:41 volumio volumio[1040]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 12 09:02:41 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand play Oct 12 09:02:41 volumio volumio[1040]: info: Oct 12 09:02:41 volumio volumio[1040]: ---------------------------- MPD announces system playlist update Oct 12 09:02:41 volumio volumio[1040]: info: Ignoring MPD Status Update Oct 12 09:02:41 volumio volumio[1040]: info: Oct 12 09:02:41 volumio volumio[1040]: ---------------------------- MPD announces system playlist update Oct 12 09:02:41 volumio volumio[1040]: info: Ignoring MPD Status Update Oct 12 09:02:41 volumio volumio[1040]: info: Oct 12 09:02:41 volumio volumio[1040]: ---------------------------- MPD announces system playlist update Oct 12 09:02:41 volumio volumio[1040]: info: Ignoring MPD Status Update Oct 12 09:02:42 volumio volumio[1040]: info: ------------------------------ 33ms Oct 12 09:02:42 volumio volumio[1040]: info: sendMpdCommand play took 28 milliseconds Oct 12 09:02:42 volumio volumio[1040]: info: ------------------------------ 23ms Oct 12 09:02:42 volumio volumio[1040]: info: ------------------------------ 17ms Oct 12 09:02:42 volumio volumio[1040]: info: ------------------------------ 16ms Oct 12 09:02:42 volumio volumio[1040]: info: CoreCommandRouter::volumioPlay Oct 12 09:02:42 volumio volumio[1040]: info: CoreStateMachine::play index undefined Oct 12 09:02:42 volumio volumio[1040]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 09:02:42 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:42 volumio volumio[1040]: info: CoreStateMachine::startPlaybackTimer Oct 12 09:02:42 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:42 volumio volumio[1040]: info: [1728694962028] ControllerUPNPBrowser::clearAddPlayTrack Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand stop Oct 12 09:02:42 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 12 09:02:42 volumio volumio[1040]: info: Oct 12 09:02:42 volumio volumio[1040]: ---------------------------- MPD announces state update: player Oct 12 09:02:42 volumio volumio[1040]: info: sendMpdCommand stop took 9 milliseconds Oct 12 09:02:42 volumio volumio[1040]: info: ControllerMpd::getState Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand status Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand clear Oct 12 09:02:42 volumio volumio[1040]: info: Oct 12 09:02:42 volumio volumio[1040]: ---------------------------- MPD announces state update: player Oct 12 09:02:42 volumio volumio[1040]: info: ControllerMpd::getState Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand status Oct 12 09:02:42 volumio volumio[1040]: info: Oct 12 09:02:42 volumio volumio[1040]: ---------------------------- MPD announces state update: player Oct 12 09:02:42 volumio volumio[1040]: info: ControllerMpd::getState Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand status Oct 12 09:02:42 volumio volumio[1040]: info: Oct 12 09:02:42 volumio volumio[1040]: ---------------------------- MPD announces state update: player Oct 12 09:02:42 volumio volumio[1040]: info: ControllerMpd::getState Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand status Oct 12 09:02:42 volumio volumio[1040]: info: Oct 12 09:02:42 volumio volumio[1040]: ---------------------------- MPD announces system playlist update Oct 12 09:02:42 volumio volumio[1040]: info: Ignoring MPD Status Update Oct 12 09:02:42 volumio volumio[1040]: info: sendMpdCommand status took 15 milliseconds Oct 12 09:02:42 volumio volumio[1040]: info: sendMpdCommand clear took 15 milliseconds Oct 12 09:02:42 volumio volumio[1040]: info: sendMpdCommand status took 13 milliseconds Oct 12 09:02:42 volumio volumio[1040]: info: sendMpdCommand status took 10 milliseconds Oct 12 09:02:42 volumio volumio[1040]: info: sendMpdCommand status took 8 milliseconds Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::parseState Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.3.75:8200/MediaItems/142.dsd" Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::parseState Oct 12 09:02:42 volumio volumio[1040]: info: ControllerMpd::pushState Oct 12 09:02:42 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 12 09:02:42 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:42 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:42 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:42 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:42 volumio volumio[1040]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 12 09:02:42 volumio volumio[1040]: verbose: CURRENT POSITION 0 Oct 12 09:02:42 volumio volumio[1040]: info: CoreStateMachine::syncState stateService stop Oct 12 09:02:42 volumio volumio[1040]: info: CoreStateMachine::syncState currentStatus stop Oct 12 09:02:42 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:42 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:42 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:42 volumio volumio[1040]: info: No code Oct 12 09:02:42 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:42 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:42 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:42 volumio volumio[1040]: info: ControllerMpd::pushState Oct 12 09:02:42 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 12 09:02:42 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:42 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:42 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:42 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:42 volumio volumio[1040]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 12 09:02:42 volumio volumio[1040]: verbose: CURRENT POSITION 0 Oct 12 09:02:42 volumio volumio[1040]: info: CoreStateMachine::syncState stateService stop Oct 12 09:02:42 volumio volumio[1040]: info: CoreStateMachine::syncState currentStatus stop Oct 12 09:02:42 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:42 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:42 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:42 volumio volumio[1040]: info: No code Oct 12 09:02:42 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:42 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:42 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:42 volumio volumio[1040]: info: ControllerMpd::pushState Oct 12 09:02:42 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 12 09:02:42 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:42 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:42 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:42 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:42 volumio volumio[1040]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 12 09:02:42 volumio volumio[1040]: verbose: CURRENT POSITION 0 Oct 12 09:02:42 volumio volumio[1040]: info: CoreStateMachine::syncState stateService stop Oct 12 09:02:42 volumio volumio[1040]: info: CoreStateMachine::syncState currentStatus stop Oct 12 09:02:42 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:42 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:42 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:42 volumio volumio[1040]: info: No code Oct 12 09:02:42 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:42 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:42 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:42 volumio volumio[1040]: info: ------------------------------ 268ms Oct 12 09:02:42 volumio volumio[1040]: info: ------------------------------ 266ms Oct 12 09:02:42 volumio volumio[1040]: info: ------------------------------ 265ms Oct 12 09:02:42 volumio volumio[1040]: info: Oct 12 09:02:42 volumio volumio[1040]: ---------------------------- MPD announces system playlist update Oct 12 09:02:42 volumio volumio[1040]: info: Ignoring MPD Status Update Oct 12 09:02:42 volumio volumio[1040]: info: Oct 12 09:02:42 volumio volumio[1040]: ---------------------------- MPD announces system playlist update Oct 12 09:02:42 volumio volumio[1040]: info: Ignoring MPD Status Update Oct 12 09:02:42 volumio volumio[1040]: info: Oct 12 09:02:42 volumio volumio[1040]: ---------------------------- MPD announces system playlist update Oct 12 09:02:42 volumio volumio[1040]: info: Ignoring MPD Status Update Oct 12 09:02:42 volumio volumio[1040]: error: updateQueue error: null Oct 12 09:02:42 volumio volumio[1040]: error: updateQueue error: null Oct 12 09:02:42 volumio volumio[1040]: error: updateQueue error: null Oct 12 09:02:42 volumio volumio[1040]: error: updateQueue error: null Oct 12 09:02:42 volumio volumio[1040]: info: ------------------------------ 411ms Oct 12 09:02:42 volumio volumio[1040]: info: sendMpdCommand playlistinfo took 405 milliseconds Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.3.75:8200/MediaItems/142.dsd" Oct 12 09:02:42 volumio volumio[1040]: info: ------------------------------ 151ms Oct 12 09:02:42 volumio volumio[1040]: info: ------------------------------ 144ms Oct 12 09:02:42 volumio volumio[1040]: info: ------------------------------ 143ms Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::parseTrackInfo Oct 12 09:02:42 volumio volumio[1040]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 12 09:02:42 volumio volumio[1040]: info: ------------------------------ 446ms Oct 12 09:02:42 volumio volumio[1040]: info: Oct 12 09:02:42 volumio volumio[1040]: ---------------------------- MPD announces system playlist update Oct 12 09:02:42 volumio volumio[1040]: info: Ignoring MPD Status Update Oct 12 09:02:42 volumio volumio[1040]: info: sendMpdCommand add "http://192.168.3.75:8200/MediaItems/142.dsd" took 99 milliseconds Oct 12 09:02:42 volumio volumio[1040]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand play Oct 12 09:02:42 volumio volumio[1040]: info: Oct 12 09:02:42 volumio volumio[1040]: ---------------------------- MPD announces system playlist update Oct 12 09:02:42 volumio volumio[1040]: info: Ignoring MPD Status Update Oct 12 09:02:42 volumio volumio[1040]: info: Oct 12 09:02:42 volumio volumio[1040]: ---------------------------- MPD announces system playlist update Oct 12 09:02:42 volumio volumio[1040]: info: Ignoring MPD Status Update Oct 12 09:02:42 volumio volumio[1040]: info: Oct 12 09:02:42 volumio volumio[1040]: ---------------------------- MPD announces system playlist update Oct 12 09:02:42 volumio volumio[1040]: info: Ignoring MPD Status Update Oct 12 09:02:42 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 12 09:02:42 volumio volumio[1040]: info: Oct 12 09:02:42 volumio volumio[1040]: ---------------------------- MPD announces state update: player Oct 12 09:02:42 volumio volumio[1040]: info: ------------------------------ 39ms Oct 12 09:02:42 volumio volumio[1040]: info: sendMpdCommand play took 30 milliseconds Oct 12 09:02:42 volumio volumio[1040]: info: ------------------------------ 25ms Oct 12 09:02:42 volumio volumio[1040]: info: ------------------------------ 24ms Oct 12 09:02:42 volumio volumio[1040]: info: ------------------------------ 20ms Oct 12 09:02:42 volumio volumio[1040]: info: ControllerMpd::getState Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand status Oct 12 09:02:42 volumio volumio[1040]: info: Oct 12 09:02:42 volumio volumio[1040]: ---------------------------- MPD announces state update: player Oct 12 09:02:42 volumio volumio[1040]: info: ControllerMpd::getState Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand status Oct 12 09:02:42 volumio volumio[1040]: info: Oct 12 09:02:42 volumio volumio[1040]: ---------------------------- MPD announces state update: player Oct 12 09:02:42 volumio volumio[1040]: info: ControllerMpd::getState Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand status Oct 12 09:02:42 volumio volumio[1040]: info: Oct 12 09:02:42 volumio volumio[1040]: ---------------------------- MPD announces state update: player Oct 12 09:02:42 volumio volumio[1040]: info: ControllerMpd::getState Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand status Oct 12 09:02:42 volumio volumio[1040]: info: sendMpdCommand status took 265 milliseconds Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::parseState Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 09:02:42 volumio volumio[1040]: info: Oct 12 09:02:42 volumio volumio[1040]: ---------------------------- MPD announces state update: player Oct 12 09:02:42 volumio volumio[1040]: info: ControllerMpd::getState Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand status Oct 12 09:02:42 volumio volumio[1040]: info: sendMpdCommand status took 295 milliseconds Oct 12 09:02:42 volumio volumio[1040]: info: sendMpdCommand status took 284 milliseconds Oct 12 09:02:42 volumio volumio[1040]: info: sendMpdCommand status took 286 milliseconds Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::parseState Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::parseState Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::parseState Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 09:02:42 volumio volumio[1040]: info: Oct 12 09:02:42 volumio volumio[1040]: ---------------------------- MPD announces state update: player Oct 12 09:02:42 volumio volumio[1040]: info: ControllerMpd::getState Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand status Oct 12 09:02:42 volumio volumio[1040]: info: Oct 12 09:02:42 volumio volumio[1040]: ---------------------------- MPD announces state update: player Oct 12 09:02:42 volumio volumio[1040]: info: ControllerMpd::getState Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand status Oct 12 09:02:42 volumio volumio[1040]: info: Oct 12 09:02:42 volumio volumio[1040]: ---------------------------- MPD announces state update: player Oct 12 09:02:42 volumio volumio[1040]: info: ControllerMpd::getState Oct 12 09:02:42 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand status Oct 12 09:02:43 volumio volumio[1040]: info: sendMpdCommand playlistinfo took 82 milliseconds Oct 12 09:02:43 volumio volumio[1040]: info: sendMpdCommand status took 86 milliseconds Oct 12 09:02:43 volumio volumio[1040]: info: sendMpdCommand playlistinfo took 71 milliseconds Oct 12 09:02:43 volumio volumio[1040]: info: sendMpdCommand playlistinfo took 73 milliseconds Oct 12 09:02:43 volumio volumio[1040]: info: sendMpdCommand playlistinfo took 68 milliseconds Oct 12 09:02:43 volumio volumio[1040]: info: sendMpdCommand status took 50 milliseconds Oct 12 09:02:43 volumio volumio[1040]: info: sendMpdCommand status took 48 milliseconds Oct 12 09:02:43 volumio volumio[1040]: verbose: ControllerMpd::parseTrackInfo Oct 12 09:02:43 volumio volumio[1040]: verbose: ControllerMpd::parseState Oct 12 09:02:43 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 09:02:43 volumio volumio[1040]: verbose: ControllerMpd::parseTrackInfo Oct 12 09:02:43 volumio volumio[1040]: verbose: ControllerMpd::parseState Oct 12 09:02:43 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 09:02:43 volumio volumio[1040]: verbose: ControllerMpd::parseState Oct 12 09:02:43 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 09:02:43 volumio volumio[1040]: info: ControllerMpd::pushState Oct 12 09:02:43 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 12 09:02:43 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:43 volumio volumio[1040]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":290,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"142.dsd","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/142.dsd","trackType":"dsd"} Oct 12 09:02:43 volumio volumio[1040]: verbose: CURRENT POSITION 0 Oct 12 09:02:43 volumio volumio[1040]: info: CoreStateMachine::syncState stateService play Oct 12 09:02:43 volumio volumio[1040]: info: CoreStateMachine::syncState currentStatus stop Oct 12 09:02:43 volumio volumio[1040]: info: ControllerMpd::pushState Oct 12 09:02:43 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 12 09:02:43 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:43 volumio volumio[1040]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":290,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"142.dsd","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/142.dsd","trackType":"dsd"} Oct 12 09:02:43 volumio volumio[1040]: verbose: CURRENT POSITION 0 Oct 12 09:02:43 volumio volumio[1040]: info: CoreStateMachine::syncState stateService play Oct 12 09:02:43 volumio volumio[1040]: info: CoreStateMachine::syncState currentStatus play Oct 12 09:02:43 volumio volumio[1040]: info: Received an update from plugin. extracting info from payload Oct 12 09:02:43 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:43 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 09:02:43 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:43 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:43 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:43 volumio volumio[1040]: info: ControllerMpd::pushState Oct 12 09:02:43 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 12 09:02:43 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:43 volumio volumio[1040]: verbose: STATE SERVICE {"status":"play","position":0,"seek":39,"duration":290,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"142.dsd","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/142.dsd","trackType":"dsd"} Oct 12 09:02:43 volumio volumio[1040]: verbose: CURRENT POSITION 0 Oct 12 09:02:43 volumio volumio[1040]: info: CoreStateMachine::syncState stateService play Oct 12 09:02:43 volumio volumio[1040]: info: CoreStateMachine::syncState currentStatus play Oct 12 09:02:43 volumio volumio[1040]: info: Received an update from plugin. extracting info from payload Oct 12 09:02:43 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:43 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:43 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:43 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:43 volumio volumio[1040]: info: ControllerMpd::pushState Oct 12 09:02:43 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 12 09:02:43 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:43 volumio volumio[1040]: verbose: STATE SERVICE {"status":"play","position":0,"seek":39,"duration":290,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"142.dsd","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/142.dsd","trackType":"dsd"} Oct 12 09:02:43 volumio volumio[1040]: verbose: CURRENT POSITION 0 Oct 12 09:02:43 volumio volumio[1040]: info: CoreStateMachine::syncState stateService play Oct 12 09:02:43 volumio volumio[1040]: info: CoreStateMachine::syncState currentStatus play Oct 12 09:02:43 volumio volumio[1040]: info: Received an update from plugin. extracting info from payload Oct 12 09:02:43 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:43 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:43 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:43 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:43 volumio volumio[1040]: info: ------------------------------ 569ms Oct 12 09:02:43 volumio volumio[1040]: info: ------------------------------ 826ms Oct 12 09:02:43 volumio volumio[1040]: info: ------------------------------ 829ms Oct 12 09:02:43 volumio volumio[1040]: info: ------------------------------ 824ms Oct 12 09:02:43 volumio volumio[1040]: info: sendMpdCommand status took 503 milliseconds Oct 12 09:02:43 volumio volumio[1040]: info: sendMpdCommand playlistinfo took 457 milliseconds Oct 12 09:02:43 volumio volumio[1040]: info: sendMpdCommand playlistinfo took 450 milliseconds Oct 12 09:02:43 volumio volumio[1040]: info: sendMpdCommand playlistinfo took 447 milliseconds Oct 12 09:02:43 volumio volumio[1040]: verbose: ControllerMpd::parseState Oct 12 09:02:43 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 09:02:43 volumio volumio[1040]: verbose: ControllerMpd::parseTrackInfo Oct 12 09:02:43 volumio volumio[1040]: verbose: ControllerMpd::parseTrackInfo Oct 12 09:02:43 volumio volumio[1040]: verbose: ControllerMpd::parseTrackInfo Oct 12 09:02:43 volumio volumio[1040]: info: ControllerMpd::pushState Oct 12 09:02:43 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 12 09:02:43 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:43 volumio volumio[1040]: verbose: STATE SERVICE {"status":"play","position":0,"seek":250,"duration":290,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"142.dsd","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/142.dsd","trackType":"dsd"} Oct 12 09:02:43 volumio volumio[1040]: verbose: CURRENT POSITION 0 Oct 12 09:02:43 volumio volumio[1040]: info: CoreStateMachine::syncState stateService play Oct 12 09:02:43 volumio volumio[1040]: info: CoreStateMachine::syncState currentStatus play Oct 12 09:02:43 volumio volumio[1040]: info: Received an update from plugin. extracting info from payload Oct 12 09:02:43 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:43 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 09:02:43 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:43 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:43 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:43 volumio volumio[1040]: info: ControllerMpd::pushState Oct 12 09:02:43 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 12 09:02:43 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:43 volumio volumio[1040]: verbose: STATE SERVICE {"status":"play","position":0,"seek":318,"duration":290,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"142.dsd","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/142.dsd","trackType":"dsd"} Oct 12 09:02:43 volumio volumio[1040]: verbose: CURRENT POSITION 0 Oct 12 09:02:43 volumio volumio[1040]: info: CoreStateMachine::syncState stateService play Oct 12 09:02:43 volumio volumio[1040]: info: CoreStateMachine::syncState currentStatus play Oct 12 09:02:43 volumio volumio[1040]: info: Received an update from plugin. extracting info from payload Oct 12 09:02:43 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:43 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:43 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:43 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:43 volumio volumio[1040]: info: ControllerMpd::pushState Oct 12 09:02:43 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 12 09:02:43 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:43 volumio volumio[1040]: verbose: STATE SERVICE {"status":"play","position":0,"seek":318,"duration":290,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"142.dsd","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/142.dsd","trackType":"dsd"} Oct 12 09:02:43 volumio volumio[1040]: verbose: CURRENT POSITION 0 Oct 12 09:02:43 volumio volumio[1040]: info: CoreStateMachine::syncState stateService play Oct 12 09:02:43 volumio volumio[1040]: info: CoreStateMachine::syncState currentStatus play Oct 12 09:02:43 volumio volumio[1040]: info: Received an update from plugin. extracting info from payload Oct 12 09:02:43 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:43 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:43 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:43 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:44 volumio volumio[1040]: info: ------------------------------ 1207ms Oct 12 09:02:44 volumio volumio[1040]: info: ------------------------------ 1171ms Oct 12 09:02:44 volumio volumio[1040]: info: ------------------------------ 1168ms Oct 12 09:02:44 volumio volumio[1040]: STREAMING PROXY: Starting server on port 3245 Oct 12 09:02:44 volumio volumio[1040]: Node JS runtime: 14 Oct 12 09:02:44 volumio volumio[1040]: info: CoreCommandRouter::volumioPlay Oct 12 09:02:44 volumio volumio[1040]: info: CoreStateMachine::play index undefined Oct 12 09:02:44 volumio volumio[1040]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 09:02:44 volumio volumio[1040]: info: CoreCommandRouter::volumioPause Oct 12 09:02:44 volumio volumio[1040]: info: CoreStateMachine::pause Oct 12 09:02:44 volumio volumio[1040]: info: CoreStateMachine::stPlaybackTimer Oct 12 09:02:44 volumio volumio[1040]: info: CoreStateMachine::servicePause Oct 12 09:02:44 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:44 volumio volumio[1040]: info: CoreCommandRouter::servicePause Oct 12 09:02:44 volumio volumio[1040]: info: [1728694964410] ControllerUPNPBrowser::pause Oct 12 09:02:44 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand pause Oct 12 09:02:44 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:44 volumio volumio[1040]: info: CoreStateMachine::startPlaybackTimer Oct 12 09:02:44 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:44 volumio volumio[1040]: info: [1728694964431] ControllerUPNPBrowser::resume Oct 12 09:02:44 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand play Oct 12 09:02:44 volumio volumio[1040]: info: Oct 12 09:02:44 volumio volumio[1040]: ---------------------------- MPD announces state update: player Oct 12 09:02:44 volumio volumio[1040]: info: sendMpdCommand playlistinfo took 1006 milliseconds Oct 12 09:02:44 volumio volumio[1040]: info: sendMpdCommand pause took 81 milliseconds Oct 12 09:02:44 volumio volumio[1040]: info: sendMpdCommand play took 58 milliseconds Oct 12 09:02:44 volumio volumio[1040]: info: ControllerMpd::getState Oct 12 09:02:44 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand status Oct 12 09:02:44 volumio volumio[1040]: verbose: ControllerMpd::parseTrackInfo Oct 12 09:02:44 volumio volumio[1040]: info: ControllerMpd::pushState Oct 12 09:02:44 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 12 09:02:44 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:44 volumio volumio[1040]: verbose: STATE SERVICE {"status":"play","position":0,"seek":341,"duration":290,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"142.dsd","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/142.dsd","trackType":"dsd"} Oct 12 09:02:44 volumio volumio[1040]: verbose: CURRENT POSITION 0 Oct 12 09:02:44 volumio volumio[1040]: info: CoreStateMachine::syncState stateService play Oct 12 09:02:44 volumio volumio[1040]: info: CoreStateMachine::syncState currentStatus pause Oct 12 09:02:44 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:44 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:44 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 09:02:44 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:44 volumio volumio[1040]: info: ------------------------------ 1603ms Oct 12 09:02:44 volumio volumio[1040]: info: sendMpdCommand status took 93 milliseconds Oct 12 09:02:44 volumio volumio[1040]: verbose: ControllerMpd::parseState Oct 12 09:02:44 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 09:02:44 volumio volumio[1040]: info: Oct 12 09:02:44 volumio volumio[1040]: ---------------------------- MPD announces state update: player Oct 12 09:02:44 volumio volumio[1040]: info: ControllerMpd::getState Oct 12 09:02:44 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand status Oct 12 09:02:44 volumio volumio[1040]: info: Oct 12 09:02:44 volumio volumio[1040]: ---------------------------- MPD announces state update: player Oct 12 09:02:44 volumio volumio[1040]: info: ControllerMpd::getState Oct 12 09:02:44 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand status Oct 12 09:02:44 volumio volumio[1040]: info: Oct 12 09:02:44 volumio volumio[1040]: ---------------------------- MPD announces state update: player Oct 12 09:02:44 volumio volumio[1040]: info: ControllerMpd::getState Oct 12 09:02:44 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand status Oct 12 09:02:44 volumio volumio[1040]: info: sendMpdCommand playlistinfo took 89 milliseconds Oct 12 09:02:44 volumio volumio[1040]: info: sendMpdCommand status took 86 milliseconds Oct 12 09:02:44 volumio volumio[1040]: info: sendMpdCommand status took 85 milliseconds Oct 12 09:02:44 volumio volumio[1040]: info: sendMpdCommand status took 71 milliseconds Oct 12 09:02:44 volumio volumio[1040]: verbose: ControllerMpd::parseTrackInfo Oct 12 09:02:44 volumio volumio[1040]: verbose: ControllerMpd::parseState Oct 12 09:02:44 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 09:02:44 volumio volumio[1040]: verbose: ControllerMpd::parseState Oct 12 09:02:44 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 09:02:44 volumio volumio[1040]: verbose: ControllerMpd::parseState Oct 12 09:02:44 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 09:02:44 volumio volumio[1040]: info: ControllerMpd::pushState Oct 12 09:02:44 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 12 09:02:44 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:44 volumio volumio[1040]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2259,"duration":290,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"142.dsd","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/142.dsd","trackType":"dsd"} Oct 12 09:02:44 volumio volumio[1040]: verbose: CURRENT POSITION 0 Oct 12 09:02:44 volumio volumio[1040]: info: CoreStateMachine::syncState stateService play Oct 12 09:02:44 volumio volumio[1040]: info: CoreStateMachine::syncState currentStatus play Oct 12 09:02:44 volumio volumio[1040]: info: Received an update from plugin. extracting info from payload Oct 12 09:02:44 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:44 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:44 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 09:02:44 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:44 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:44 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:44 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:44 volumio volumio[1040]: info: ------------------------------ 345ms Oct 12 09:02:44 volumio volumio[1040]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Celine%20Dion/29f85334-bc57-4ba2-b5c3-0d4ec376b6cc.jpg' Oct 12 09:02:44 volumio volumio[1040]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Celine%20Dion/29f85334-bc57-4ba2-b5c3-0d4ec376b6cc.jpg' Oct 12 09:02:44 volumio volumio[1040]: info: sendMpdCommand playlistinfo took 128 milliseconds Oct 12 09:02:44 volumio volumio[1040]: info: sendMpdCommand playlistinfo took 129 milliseconds Oct 12 09:02:44 volumio volumio[1040]: verbose: ControllerMpd::parseTrackInfo Oct 12 09:02:44 volumio volumio[1040]: info: ControllerMpd::pushState Oct 12 09:02:44 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 12 09:02:44 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:44 volumio volumio[1040]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2424,"duration":290,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"142.dsd","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/142.dsd","trackType":"dsd"} Oct 12 09:02:44 volumio volumio[1040]: verbose: CURRENT POSITION 0 Oct 12 09:02:44 volumio volumio[1040]: info: CoreStateMachine::syncState stateService play Oct 12 09:02:44 volumio volumio[1040]: info: CoreStateMachine::syncState currentStatus play Oct 12 09:02:44 volumio volumio[1040]: info: Received an update from plugin. extracting info from payload Oct 12 09:02:44 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:44 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:44 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 09:02:44 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:44 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:44 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:44 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:44 volumio volumio[1040]: info: ControllerMpd::pushState Oct 12 09:02:44 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 12 09:02:44 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:44 volumio volumio[1040]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2441,"duration":290,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"142.dsd","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/142.dsd","trackType":"dsd"} Oct 12 09:02:44 volumio volumio[1040]: verbose: CURRENT POSITION 0 Oct 12 09:02:44 volumio volumio[1040]: info: CoreStateMachine::syncState stateService play Oct 12 09:02:44 volumio volumio[1040]: info: CoreStateMachine::syncState currentStatus play Oct 12 09:02:44 volumio volumio[1040]: info: Received an update from plugin. extracting info from payload Oct 12 09:02:44 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:44 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:44 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 09:02:44 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:44 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:44 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:44 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:44 volumio volumio[1040]: info: ControllerMpd::pushState Oct 12 09:02:44 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 12 09:02:44 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:44 volumio volumio[1040]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2475,"duration":290,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"142.dsd","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/142.dsd","trackType":"dsd"} Oct 12 09:02:44 volumio volumio[1040]: verbose: CURRENT POSITION 0 Oct 12 09:02:44 volumio volumio[1040]: info: CoreStateMachine::syncState stateService play Oct 12 09:02:44 volumio volumio[1040]: info: CoreStateMachine::syncState currentStatus play Oct 12 09:02:44 volumio volumio[1040]: info: Received an update from plugin. extracting info from payload Oct 12 09:02:44 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:44 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:44 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 09:02:44 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:44 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:02:44 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:44 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:02:45 volumio volumio[1040]: info: ------------------------------ 488ms Oct 12 09:02:45 volumio volumio[1040]: info: ------------------------------ 483ms Oct 12 09:02:45 volumio volumio[1040]: info: ------------------------------ 476ms Oct 12 09:02:50 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 09:02:50 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 09:02:50 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 12 09:02:50 volumio volumio-remote-updater[712]: No test mode Oct 12 09:02:50 volumio volumio-remote-updater[712]: No alpha test mode Oct 12 09:02:50 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Oct 12 09:02:53 volumio volumio[1040]: info: CoreCommandRouter::volumioGetState Oct 12 09:02:53 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:53 volumio sudo[1897]: root : TTY=unknown ; PWD=/data/plugins/user_interface/peppy_screensaver ; USER=root ; COMMAND=/usr/bin/python3 ./screensaver/volumio_peppymeter.py Oct 12 09:02:53 volumio sudo[1897]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 09:02:53 volumio volumio[1040]: info: CoreCommandRouter::volumioGetState Oct 12 09:02:53 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:54 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 12 09:02:54 volumio volumio[1040]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Oct 12 09:02:54 volumio volumio[1040]: info: CoreCommandRouter::volumioGetState Oct 12 09:02:54 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:02:57 volumio volumio[1040]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

FIXES



    • Improved translations
    • Fix for Wizard not showing on second start
    • Fix for Playback Queue not advancing

 

NEW ADDITIONS

 

    • Add DSD Quirk for Marantz SA-12 on Rivo and Primo v2

 

","title":"Update v3.757","updateavailable":true} Oct 12 09:02:57 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Oct 12 09:02:59 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:02:59 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 12 09:02:59 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 12 09:02:59 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 12 09:02:59 volumio volumio[1040]: info: CoreCommandRouter::volumioGetBrowseSources Oct 12 09:02:59 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 09:02:59 volumio volumio[1040]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 9 Oct 12 09:02:59 volumio volumio[1040]: info: CoreCommandRouter::volumioGetState Oct 12 09:02:59 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:03:01 volumio volumio[1040]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 9 Oct 12 09:03:01 volumio volumio[1040]: info: CoreCommandRouter::volumioGetState Oct 12 09:03:01 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:03:01 volumio volumio[1040]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Celine%20Dion/29f85334-bc57-4ba2-b5c3-0d4ec376b6cc.jpg' Oct 12 09:03:01 volumio volumio[1040]: error: MyVolumio Plugin failed to authenticate in a timely fashion Oct 12 09:03:01 volumio volumio[1040]: info: Completed starting MyVolumio Plugin Oct 12 09:03:01 volumio volumio[1040]: info: BOOT COMPLETED Oct 12 09:03:01 volumio volumio[1040]: [Metrics] CommandRouter: 58s 55.22ms Oct 12 09:03:01 volumio volumio[1040]: info: CoreCommandRouter::volumiosetStartupVolume Oct 12 09:03:01 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 09:03:01 volumio volumio[1040]: info: VolumeController:: Setting startup Volume 20 Oct 12 09:03:01 volumio volumio[1040]: info: VolumeController::SetAlsaVolume20 Oct 12 09:03:01 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 09:03:01 volumio volumio[1040]: info: CoreCommandRouter::Close All Modals sent Oct 12 09:03:01 volumio volumio[1040]: info: CoreCommandRouter::Close All Modals sent Oct 12 09:03:01 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:03:01 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:03:01 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 09:03:01 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:03:01 volumio volumio[1040]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav Oct 12 09:03:01 volumio volumio[1040]: ALSA lib pcm_hw.c:1822:(_snd_pcm_hw_open) Invalid value for card Oct 12 09:03:01 volumio volumio[1040]: aplay: main:828: audio open error: No such device Oct 12 09:03:02 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Oct 12 09:03:02 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 12 09:03:02 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Oct 12 09:03:11 volumio volumio[1040]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. Oct 12 09:03:11 volumio volumio[1040]: info: Retrying Login Due to Network Error Oct 12 09:03:21 volumio volumio[1040]: info: MyVolumio login type: Token Oct 12 09:03:23 volumio volumio[1040]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 12 09:03:23 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 12 09:03:23 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 09:03:23 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 12 09:03:24 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 09:03:24 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 09:03:24 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 09:03:24 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 09:03:24 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 09:03:24 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 09:03:24 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 09:03:24 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Oct 12 09:03:24 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 12 09:03:30 volumio volumio[1040]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Oct 12 09:03:30 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Oct 12 09:03:30 volumio volumio[1040]: info: Preparing to save Alsa Options, stopping services first Oct 12 09:03:30 volumio volumio[1040]: info: CoreCommandRouter::volumioGetState Oct 12 09:03:30 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:03:30 volumio volumio[1040]: info: CoreCommandRouter::volumioPause Oct 12 09:03:30 volumio volumio[1040]: info: CoreStateMachine::pause Oct 12 09:03:30 volumio volumio[1040]: info: CoreStateMachine::stPlaybackTimer Oct 12 09:03:30 volumio volumio[1040]: info: CoreStateMachine::servicePause Oct 12 09:03:30 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:03:30 volumio volumio[1040]: info: CoreCommandRouter::servicePause Oct 12 09:03:30 volumio volumio[1040]: info: [1728695010784] ControllerUPNPBrowser::pause Oct 12 09:03:30 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand pause Oct 12 09:03:30 volumio volumio[1040]: info: Saving Audio Output to: {"output_device":{"value":"1,0","label":"Analog Out"}} Oct 12 09:03:30 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 12 09:03:30 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 12 09:03:30 volumio volumio[1040]: info: Found match in Cards Database: setting mixer for card Analog Out Oct 12 09:03:31 volumio volumio[1040]: info: Setting default mixerSoftMaster for Softvolume device Oct 12 09:03:31 volumio volumio[1040]: info: CoreCommandRouter::volumioUpdateVolumeSettings Oct 12 09:03:31 volumio volumio[1040]: info: Updating Volume Controller Parameters: Device: 1,0 Name: softvolume Mixer: SoftMaster Max Vol: 20 Vol Curve; logarithmic Vol Steps: 1 Oct 12 09:03:31 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Oct 12 09:03:31 volumio volumio[1040]: info: Disabling external Volume Control Oct 12 09:03:31 volumio volumio[1040]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 12 09:03:31 volumio volumio[1040]: info: Enable softmixer device for audio device undefined Oct 12 09:03:31 volumio volumio[1040]: info: Oct 12 09:03:31 volumio volumio[1040]: ---------------------------- MPD announces state update: player Oct 12 09:03:31 volumio volumio[1040]: info: sendMpdCommand pause took 487 milliseconds Oct 12 09:03:31 volumio volumio[1040]: info: ControllerMpd::getState Oct 12 09:03:31 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand status Oct 12 09:03:31 volumio volumio[1040]: info: sendMpdCommand status took 4 milliseconds Oct 12 09:03:31 volumio volumio[1040]: verbose: ControllerMpd::parseState Oct 12 09:03:31 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 09:03:31 volumio volumio[1040]: info: Oct 12 09:03:31 volumio volumio[1040]: ---------------------------- MPD announces state update: player Oct 12 09:03:31 volumio volumio[1040]: info: ControllerMpd::getState Oct 12 09:03:31 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand status Oct 12 09:03:31 volumio volumio[1040]: info: Oct 12 09:03:31 volumio volumio[1040]: ---------------------------- MPD announces state update: player Oct 12 09:03:31 volumio volumio[1040]: info: ControllerMpd::getState Oct 12 09:03:31 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand status Oct 12 09:03:31 volumio volumio[1040]: info: Oct 12 09:03:31 volumio volumio[1040]: ---------------------------- MPD announces state update: player Oct 12 09:03:31 volumio volumio[1040]: info: ControllerMpd::getState Oct 12 09:03:31 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand status Oct 12 09:03:31 volumio volumio[1040]: info: Software Volume ALSA configuration written Oct 12 09:03:31 volumio volumio[1040]: info: Preparing to generate the ALSA configuration file Oct 12 09:03:31 volumio volumio[1040]: info: sendMpdCommand playlistinfo took 33 milliseconds Oct 12 09:03:31 volumio volumio[1040]: info: sendMpdCommand status took 29 milliseconds Oct 12 09:03:31 volumio volumio[1040]: info: sendMpdCommand status took 27 milliseconds Oct 12 09:03:31 volumio volumio[1040]: info: sendMpdCommand status took 22 milliseconds Oct 12 09:03:31 volumio volumio[1040]: verbose: ControllerMpd::parseTrackInfo Oct 12 09:03:31 volumio volumio[1040]: verbose: ControllerMpd::parseState Oct 12 09:03:31 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 09:03:31 volumio volumio[1040]: verbose: ControllerMpd::parseState Oct 12 09:03:31 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 09:03:31 volumio volumio[1040]: verbose: ControllerMpd::parseState Oct 12 09:03:31 volumio volumio[1040]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 09:03:31 volumio volumio[1040]: info: ControllerMpd::pushState Oct 12 09:03:31 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 12 09:03:31 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:03:31 volumio volumio[1040]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":49437,"duration":290,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"142.dsd","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/142.dsd","trackType":"dsd"} Oct 12 09:03:31 volumio volumio[1040]: verbose: CURRENT POSITION 0 Oct 12 09:03:31 volumio volumio[1040]: info: CoreStateMachine::syncState stateService pause Oct 12 09:03:31 volumio volumio[1040]: info: CoreStateMachine::syncState currentStatus pause Oct 12 09:03:31 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:03:31 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:03:31 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 09:03:31 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:03:31 volumio volumio[1040]: info: CoreStateMachine::stPlaybackTimer Oct 12 09:03:31 volumio volumio[1040]: info: ------------------------------ 95ms Oct 12 09:03:31 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 12 09:03:31 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 09:03:31 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 12 09:03:31 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 09:03:31 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 09:03:31 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 09:03:31 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 09:03:31 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 09:03:31 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Oct 12 09:03:31 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 12 09:03:31 volumio volumio[1040]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Oct 12 09:03:31 volumio volumio[1040]: info: The plugin peppy_screensaver has an ALSA contribution file Peppyalsa.postPeppyalsa.5.conf Oct 12 09:03:31 volumio volumio[1040]: info: Reading ALSA contributions from plugins. Oct 12 09:03:31 volumio volumio[1040]: info: sendMpdCommand playlistinfo took 260 milliseconds Oct 12 09:03:31 volumio volumio[1040]: info: sendMpdCommand playlistinfo took 259 milliseconds Oct 12 09:03:31 volumio volumio[1040]: info: sendMpdCommand playlistinfo took 259 milliseconds Oct 12 09:03:31 volumio volumio[1040]: verbose: ControllerMpd::parseTrackInfo Oct 12 09:03:31 volumio volumio[1040]: verbose: ControllerMpd::parseTrackInfo Oct 12 09:03:31 volumio volumio[1040]: verbose: ControllerMpd::parseTrackInfo Oct 12 09:03:31 volumio volumio[1040]: info: ControllerMpd::pushState Oct 12 09:03:31 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 12 09:03:31 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:03:31 volumio volumio[1040]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":49437,"duration":290,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"142.dsd","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/142.dsd","trackType":"dsd"} Oct 12 09:03:31 volumio volumio[1040]: verbose: CURRENT POSITION 0 Oct 12 09:03:31 volumio volumio[1040]: info: CoreStateMachine::syncState stateService pause Oct 12 09:03:31 volumio volumio[1040]: info: CoreStateMachine::syncState currentStatus pause Oct 12 09:03:31 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:03:31 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:03:31 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:03:31 volumio volumio[1040]: info: CoreStateMachine::stPlaybackTimer Oct 12 09:03:31 volumio volumio[1040]: info: ControllerMpd::pushState Oct 12 09:03:31 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 12 09:03:31 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:03:31 volumio volumio[1040]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":49437,"duration":290,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"142.dsd","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/142.dsd","trackType":"dsd"} Oct 12 09:03:31 volumio volumio[1040]: verbose: CURRENT POSITION 0 Oct 12 09:03:31 volumio volumio[1040]: info: CoreStateMachine::syncState stateService pause Oct 12 09:03:31 volumio volumio[1040]: info: CoreStateMachine::syncState currentStatus pause Oct 12 09:03:31 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:03:31 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:03:31 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:03:31 volumio volumio[1040]: info: CoreStateMachine::stPlaybackTimer Oct 12 09:03:31 volumio volumio[1040]: info: ControllerMpd::pushState Oct 12 09:03:31 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 12 09:03:31 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:03:31 volumio volumio[1040]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":49437,"duration":290,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"142.dsd","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/142.dsd","trackType":"dsd"} Oct 12 09:03:31 volumio volumio[1040]: verbose: CURRENT POSITION 0 Oct 12 09:03:31 volumio volumio[1040]: info: CoreStateMachine::syncState stateService pause Oct 12 09:03:31 volumio volumio[1040]: info: CoreStateMachine::syncState currentStatus pause Oct 12 09:03:31 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 12 09:03:31 volumio volumio[1040]: info: CorePlayQueue::getTrack 0 Oct 12 09:03:31 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 12 09:03:31 volumio volumio[1040]: info: CoreStateMachine::stPlaybackTimer Oct 12 09:03:31 volumio volumio[1040]: info: ------------------------------ 421ms Oct 12 09:03:31 volumio volumio[1040]: info: ------------------------------ 420ms Oct 12 09:03:31 volumio volumio[1040]: info: ------------------------------ 420ms Oct 12 09:03:31 volumio volumio[1040]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 09:03:31 volumio volumio[1040]: Error: ENOTDIR: not a directory, scandir '/tmp/peppyrunning' Oct 12 09:03:31 volumio volumio[1040]: at Object.readdirSync (fs.js:1048:3) Oct 12 09:03:31 volumio volumio[1040]: at rmkidsSync (/data/plugins/user_interface/peppy_screensaver/node_modules/rimraf/rimraf.js:349:11) Oct 12 09:03:31 volumio volumio[1040]: at rmdirSync (/data/plugins/user_interface/peppy_screensaver/node_modules/rimraf/rimraf.js:342:7) Oct 12 09:03:31 volumio volumio[1040]: at Function.rimrafSync [as sync] (/data/plugins/user_interface/peppy_screensaver/node_modules/rimraf/rimraf.js:319:62) Oct 12 09:03:31 volumio volumio[1040]: at Object.removeSync (/data/plugins/user_interface/peppy_screensaver/node_modules/fs-extra/lib/remove/index.js:4:17) Oct 12 09:03:31 volumio volumio[1040]: at Socket. (/data/plugins/user_interface/peppy_screensaver/index.js:225:48) Oct 12 09:03:31 volumio volumio[1040]: at Socket.Emitter.emit (/data/plugins/user_interface/peppy_screensaver/node_modules/component-emitter/index.js:145:20) Oct 12 09:03:31 volumio volumio[1040]: at Socket.onevent (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/socket.js:278:10) Oct 12 09:03:31 volumio volumio[1040]: at Socket.onpacket (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/socket.js:236:12) Oct 12 09:03:31 volumio volumio[1040]: at Manager. (/data/plugins/user_interface/peppy_screensaver/node_modules/component-bind/index.js:21:15) Oct 12 09:03:31 volumio volumio[1040]: at Manager.Emitter.emit (/data/plugins/user_interface/peppy_screensaver/node_modules/component-emitter/index.js:145:20) Oct 12 09:03:31 volumio volumio[1040]: at Manager.ondecoded (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/manager.js:349:8) Oct 12 09:03:31 volumio volumio[1040]: at Decoder. (/data/plugins/user_interface/peppy_screensaver/node_modules/component-bind/index.js:21:15) Oct 12 09:03:31 volumio volumio[1040]: at Decoder.Emitter.emit (/data/plugins/user_interface/peppy_screensaver/node_modules/component-emitter/index.js:145:20) Oct 12 09:03:31 volumio volumio[1040]: at Decoder.add (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-parser/index.js:251:12) Oct 12 09:03:31 volumio volumio[1040]: at Manager.ondata (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/manager.js:339:16) { Oct 12 09:03:31 volumio volumio[1040]: errno: -20, Oct 12 09:03:31 volumio volumio[1040]: syscall: 'scandir', Oct 12 09:03:31 volumio volumio[1040]: code: 'ENOTDIR', Oct 12 09:03:31 volumio volumio[1040]: path: '/tmp/peppyrunning' Oct 12 09:03:31 volumio volumio[1040]: } Oct 12 09:03:31 volumio volumio[1040]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 09:03:32 volumio sudo[2070]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-12 09:02 Oct 12 09:03:32 volumio sudo[2070]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 07:48:50 PM CEST" VOLUMIO_VERSION="3.742" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="1049be5fd382035818795b7f5c38e10d"