-- Logs begin at Fri 2024-08-23 12:47:50 CST, end at Fri 2024-08-23 12:49:46 CST. -- Aug 23 12:48:00 volumio-x86 volumio[960]: info: Loading plugin "network"... Aug 23 12:48:00 volumio-x86 volumio[960]: info: Refreshing Cached IP Addresses Aug 23 12:48:00 volumio-x86 volumio[960]: info: Loading plugin "services"... Aug 23 12:48:00 volumio-x86 volumio[960]: info: Loading plugin "alsa_controller"... Aug 23 12:48:00 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 23 12:48:00 volumio-x86 volumio[960]: info: Loading plugin "wizard"... Aug 23 12:48:00 volumio-x86 volumio[960]: info: Loading plugin "networkfs"... Aug 23 12:48:00 volumio-x86 sudo[1191]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 23 12:48:00 volumio-x86 sudo[1195]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 23 12:48:00 volumio-x86 sudo[1193]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 23 12:48:00 volumio-x86 sudo[1191]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 12:48:00 volumio-x86 sudo[1195]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 12:48:00 volumio-x86 sudo[1193]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 12:48:00 volumio-x86 sudo[1191]: pam_unix(sudo:session): session closed for user root Aug 23 12:48:00 volumio-x86 sudo[1193]: pam_unix(sudo:session): session closed for user root Aug 23 12:48:00 volumio-x86 sudo[1195]: pam_unix(sudo:session): session closed for user root Aug 23 12:48:01 volumio-x86 volumio[960]: info: Starting Udev Watcher for removable devices Aug 23 12:48:01 volumio-x86 sudo[1206]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //127.0.0.1/Internal Storage/musics /mnt/NAS/local Aug 23 12:48:01 volumio-x86 sudo[1206]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 12:48:01 volumio-x86 volumio[960]: info: Ignoring mount for partition: boot Aug 23 12:48:01 volumio-x86 volumio[960]: info: Ignoring mount for partition: volumio Aug 23 12:48:01 volumio-x86 volumio[960]: info: Ignoring mount for partition: volumio_data Aug 23 12:48:01 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 23 12:48:01 volumio-x86 volumio[960]: info: Loading plugin "volumio_command_line_client"... Aug 23 12:48:01 volumio-x86 volumio[960]: info: Loading plugin "upnp"... Aug 23 12:48:01 volumio-x86 volumio[960]: info: [1724388481124] Starting Upmpd Daemon Aug 23 12:48:01 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 23 12:48:01 volumio-x86 volumio[960]: info: Loading plugin "my_music"... Aug 23 12:48:01 volumio-x86 kernel: FS-Cache: Loaded Aug 23 12:48:01 volumio-x86 volumio[960]: info: Loading plugin "mpd"... Aug 23 12:48:01 volumio-x86 kernel: Key type dns_resolver registered Aug 23 12:48:01 volumio-x86 kernel: Key type cifs.spnego registered Aug 23 12:48:01 volumio-x86 kernel: Key type cifs.idmap registered Aug 23 12:48:01 volumio-x86 sudo[1206]: pam_unix(sudo:session): session closed for user root Aug 23 12:48:01 volumio-x86 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. Aug 23 12:48:01 volumio-x86 kernel: CIFS: Attempting to mount //127.0.0.1/Internal Storage/musics Aug 23 12:48:01 volumio-x86 kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Aug 23 12:48:01 volumio-x86 kernel: CIFS: VFS: cifs_mount failed w/return code = -111 Aug 23 12:48:01 volumio-x86 volumio[960]: info: Loading plugin "upnp_browser"... Aug 23 12:48:02 volumio-x86 volumio[960]: info: Loading plugin "alarm-clock"... Aug 23 12:48:02 volumio-x86 dbus-daemon[728]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' requested by ':1.6' (uid=0 pid=1164 comm="/usr/lib/chromium/chromium --show-component-extens") Aug 23 12:48:02 volumio-x86 systemd[1]: Starting Bluetooth service... Aug 23 12:48:02 volumio-x86 volumio[960]: info: Loading plugin "airplay_emulation"... Aug 23 12:48:02 volumio-x86 volumio[960]: info: Starting Shairport Sync Aug 23 12:48:02 volumio-x86 volumio[960]: info: Loading plugin "last_100"... Aug 23 12:48:02 volumio-x86 volumio[960]: info: Loading plugin "webradio"... Aug 23 12:48:02 volumio-x86 volumio[960]: info: Loading plugin "i2s_dacs"... Aug 23 12:48:02 volumio-x86 volumio[960]: info: I2S DAC not set, start Auto-detection Aug 23 12:48:02 volumio-x86 volumio[960]: info: Loading plugin "volumiodiscovery"... Aug 23 12:48:02 volumio-x86 volumio[960]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 23 12:48:02 volumio-x86 volumio[960]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 23 12:48:02 volumio-x86 node[960]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 23 12:48:02 volumio-x86 volumio[960]: *** WARNING *** For more information see Aug 23 12:48:02 volumio-x86 volumio[960]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 23 12:48:02 volumio-x86 volumio[960]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 23 12:48:02 volumio-x86 volumio[960]: *** WARNING *** For more information see Aug 23 12:48:02 volumio-x86 node[960]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 23 12:48:02 volumio-x86 node[960]: *** WARNING *** For more information see Aug 23 12:48:02 volumio-x86 node[960]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 23 12:48:02 volumio-x86 node[960]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 23 12:48:02 volumio-x86 node[960]: *** WARNING *** For more information see Aug 23 12:48:02 volumio-x86 volumio[960]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 23 12:48:02 volumio-x86 volumio[960]: info: Discovery: Started advertising with name: Volumio-x86 Aug 23 12:48:02 volumio-x86 kernel: Bluetooth: Core ver 2.22 Aug 23 12:48:02 volumio-x86 kernel: NET: Registered PF_BLUETOOTH protocol family Aug 23 12:48:02 volumio-x86 kernel: Bluetooth: HCI device and connection manager initialized Aug 23 12:48:02 volumio-x86 kernel: Bluetooth: HCI socket layer initialized Aug 23 12:48:02 volumio-x86 kernel: Bluetooth: L2CAP socket layer initialized Aug 23 12:48:02 volumio-x86 kernel: Bluetooth: SCO socket layer initialized Aug 23 12:48:02 volumio-x86 bluetoothd[1234]: Bluetooth daemon 5.50 Aug 23 12:48:02 volumio-x86 bluetoothd[1234]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf Aug 23 12:48:02 volumio-x86 dbus-daemon[728]: [system] Successfully activated service 'org.bluez' Aug 23 12:48:02 volumio-x86 systemd[1]: Started Bluetooth service. Aug 23 12:48:02 volumio-x86 bluetoothd[1234]: Starting SDP server Aug 23 12:48:02 volumio-x86 bluetoothd[1234]: Excluding (cli) sap Aug 23 12:48:02 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 23 12:48:02 volumio-x86 volumio[960]: info: Loading plugin "autostart"... Aug 23 12:48:02 volumio-x86 kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Aug 23 12:48:02 volumio-x86 kernel: Bluetooth: BNEP filters: protocol multicast Aug 23 12:48:02 volumio-x86 kernel: Bluetooth: BNEP socket layer initialized Aug 23 12:48:02 volumio-x86 bluetoothd[1234]: Bluetooth management interface 1.22 initialized Aug 23 12:48:02 volumio-x86 dbus-daemon[728]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.7' (uid=0 pid=1234 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") Aug 23 12:48:02 volumio-x86 systemd[1]: Starting Hostname Service... Aug 23 12:48:03 volumio-x86 dbus-daemon[728]: [system] Successfully activated service 'org.freedesktop.hostname1' Aug 23 12:48:03 volumio-x86 systemd[1]: Started Hostname Service. Aug 23 12:48:03 volumio-x86 volumio[960]: info: Applying required configuration parameters for plugin autostart Aug 23 12:48:03 volumio-x86 volumio[960]: info: AutoStart - onVolumioStart - read config.json Aug 23 12:48:03 volumio-x86 volumio[960]: info: Loading plugin "peppy_screensaver"... Aug 23 12:48:03 volumio-x86 volumio[960]: info: Applying required configuration parameters for plugin peppy_screensaver Aug 23 12:48:03 volumio-x86 volumio[960]: info: Loading plugin "outputs"... Aug 23 12:48:03 volumio-x86 volumio[960]: info: Loading plugin "albumart"... Aug 23 12:48:03 volumio-x86 volumio[960]: info: Plugin example_plugin is not enabled Aug 23 12:48:03 volumio-x86 volumio[960]: info: Loading plugin "inputs"... Aug 23 12:48:03 volumio-x86 volumio[960]: info: Loading plugin "updater_comm"... Aug 23 12:48:04 volumio-x86 volumio[960]: Forking 3 albumart workers Aug 23 12:48:04 volumio-x86 volumio[960]: info: Plugin mpdemulation is not enabled Aug 23 12:48:04 volumio-x86 volumio[960]: info: Loading plugin "rest_api"... Aug 23 12:48:04 volumio-x86 volumio[960]: info: Loading plugin "websocket"... Aug 23 12:48:04 volumio-x86 volumio[960]: info: Starting Socket.io Server version 2.3.0 Aug 23 12:48:04 volumio-x86 volumio[960]: info: Plugin RoonBridge is not enabled Aug 23 12:48:04 volumio-x86 volumio[960]: info: Loading plugin "Systeminfo"... Aug 23 12:48:04 volumio-x86 dhcpcd[830]: eth0: leased 192.168.5.182 for 86400 seconds Aug 23 12:48:04 volumio-x86 dhcpcd[830]: eth0: adding route to 192.168.5.0/24 Aug 23 12:48:04 volumio-x86 dhcpcd[830]: eth0: adding default route via 192.168.5.1 Aug 23 12:48:04 volumio-x86 avahi-daemon[734]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.5.182. Aug 23 12:48:04 volumio-x86 avahi-daemon[734]: New relevant interface eth0.IPv4 for mDNS. Aug 23 12:48:04 volumio-x86 avahi-daemon[734]: Registering new address record for 192.168.5.182 on eth0.IPv4. Aug 23 12:48:04 volumio-x86 volumio[960]: Starting albumart workers Aug 23 12:48:04 volumio-x86 volumio[960]: Starting albumart workers Aug 23 12:48:04 volumio-x86 volumio[960]: Starting albumart workers Aug 23 12:48:04 volumio-x86 volumio[960]: info: Loading i18n strings for locale zh Aug 23 12:48:04 volumio-x86 volumio[960]: Updating browse sources language Aug 23 12:48:04 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 23 12:48:04 volumio-x86 ntpd[937]: ntpd exiting on signal 15 (Terminated) Aug 23 12:48:04 volumio-x86 systemd[1]: Stopping Network Time Service... Aug 23 12:48:04 volumio-x86 systemd[1]: ntp.service: Succeeded. Aug 23 12:48:04 volumio-x86 systemd[1]: Stopped Network Time Service. Aug 23 12:48:04 volumio-x86 systemd[1]: Starting Network Time Service... Aug 23 12:48:04 volumio-x86 ntpd[1411]: ntpd 4.2.8p12@1.3728-o (1): Starting Aug 23 12:48:04 volumio-x86 ntpd[1411]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Aug 23 12:48:04 volumio-x86 systemd[1]: Started Network Time Service. Aug 23 12:48:04 volumio-x86 ntpd[1417]: proto: precision = 0.237 usec (-22) Aug 23 12:48:04 volumio-x86 ntpd[1417]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Aug 23 12:48:04 volumio-x86 ntpd[1417]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Aug 23 12:48:04 volumio-x86 ntpd[1417]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 605 days ago Aug 23 12:48:04 volumio-x86 ntpd[1417]: Listen and drop on 0 v6wildcard [::]:123 Aug 23 12:48:04 volumio-x86 ntpd[1417]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Aug 23 12:48:04 volumio-x86 ntpd[1417]: Listen normally on 2 lo 127.0.0.1:123 Aug 23 12:48:04 volumio-x86 ntpd[1417]: Listen normally on 3 eth0 192.168.5.182:123 Aug 23 12:48:04 volumio-x86 ntpd[1417]: Listening on routing socket on fd #20 for interface updates Aug 23 12:48:04 volumio-x86 ntpd[1417]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Aug 23 12:48:04 volumio-x86 ntpd[1417]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::initPlayerControls Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 23 12:48:05 volumio-x86 volumio[960]: Express server listening on port 3000 Aug 23 12:48:05 volumio-x86 volumio[960]: [Metrics] WebUI: 8s 980.95ms Aug 23 12:48:05 volumio-x86 volumio[960]: info: Setting Device type: x86 Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreStateMachine::resetVolumioState Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreStateMachine::getcurrentVolume Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioRetrievevolume Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 12:48:05 volumio-x86 volumio[960]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Aug 23 12:48:05 volumio-x86 volumio[960]: info: Completed loading Core Plugins Aug 23 12:48:05 volumio-x86 volumio[960]: info: Preparing to generate the ALSA configuration file Aug 23 12:48:05 volumio-x86 volumio[960]: info: Cannot mount NAS local at system boot, trial number 1 ,retrying in 5 seconds Aug 23 12:48:05 volumio-x86 volumio[960]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Aug 23 12:48:05 volumio-x86 volumio[960]: wlan0 Interface doesn't support scanning. Aug 23 12:48:05 volumio-x86 volumio[960]: info: Cannot use regular scanning, forcing with ap-force Aug 23 12:48:05 volumio-x86 sudo[1434]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Aug 23 12:48:05 volumio-x86 sudo[1434]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 12:48:05 volumio-x86 sudo[1434]: pam_unix(sudo:session): session closed for user root Aug 23 12:48:05 volumio-x86 volumio[960]: command failed: No such device (-19) Aug 23 12:48:05 volumio-x86 volumio[960]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Aug 23 12:48:05 volumio-x86 volumio[960]: command failed: No such device (-19) Aug 23 12:48:05 volumio-x86 volumio[960]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Aug 23 12:48:05 volumio-x86 volumio[960]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Aug 23 12:48:05 volumio-x86 volumio[960]: info: The plugin peppy_screensaver has an ALSA contribution file Peppyalsa.postPeppyalsa.5.conf Aug 23 12:48:05 volumio-x86 volumio[960]: info: Reading ALSA contributions from plugins. Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:48:05 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreStateMachine::updateTrackBlock Aug 23 12:48:05 volumio-x86 volumio[960]: info: CorePlayQueue::getTrackBlock Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioRetrievevolume Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetState Aug 23 12:48:05 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:05 volumio-x86 volumio[960]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Aug 23 12:48:05 volumio-x86 volumio[960]: info: Reloading queue from file Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:48:05 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreStateMachine::setRepeat null single undefined Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:48:05 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreStateMachine::setRandom null Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:48:05 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:48:05 volumio-x86 volumio[960]: info: Asound.conf file unchanged, so no further update is needed Aug 23 12:48:05 volumio-x86 volumio[960]: info: Output device has changed, restarting MPD Aug 23 12:48:05 volumio-x86 sudo[1469]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 23 12:48:05 volumio-x86 volumio[960]: info: Output device has changed, restarting Shairport Sync Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 12:48:05 volumio-x86 sudo[1469]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 12:48:05 volumio-x86 sudo[1469]: pam_unix(sudo:session): session closed for user root Aug 23 12:48:05 volumio-x86 sudo[1471]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 23 12:48:05 volumio-x86 sudo[1471]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 12:48:05 volumio-x86 systemd[1]: Listening on mpd.socket. Aug 23 12:48:05 volumio-x86 volumio[960]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 23 12:48:05 volumio-x86 volumio[960]: info: ___________ START PLUGINS ___________ Aug 23 12:48:05 volumio-x86 volumio[960]: info: ControllerMpd::onStart: Initializing MPD Aug 23 12:48:05 volumio-x86 volumio[960]: info: Creating MPD Configuration file Aug 23 12:48:05 volumio-x86 systemd[1]: Starting Music Player Daemon... Aug 23 12:48:05 volumio-x86 sudo[1479]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 23 12:48:05 volumio-x86 sudo[1479]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 12:48:05 volumio-x86 volumio[960]: info: [1724388485766] CoreMusicLibrary::Adding element 媒体服务器 Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 23 12:48:05 volumio-x86 sudo[1479]: pam_unix(sudo:session): session closed for user root Aug 23 12:48:05 volumio-x86 sudo[1481]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 23 12:48:05 volumio-x86 sudo[1481]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 12:48:05 volumio-x86 systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Aug 23 12:48:05 volumio-x86 systemd[1]: mpd.service: Succeeded. Aug 23 12:48:05 volumio-x86 systemd[1]: Stopped Music Player Daemon. Aug 23 12:48:05 volumio-x86 systemd[1]: Starting Music Player Daemon... Aug 23 12:48:05 volumio-x86 volumio[960]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 12:48:05 volumio-x86 volumio[960]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 23 12:48:05 volumio-x86 volumio[960]: info: [1724388485874] CoreMusicLibrary::Adding element Last_100 Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 23 12:48:05 volumio-x86 volumio[960]: info: [1724388485877] CoreMusicLibrary::Adding element Webradio Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 23 12:48:05 volumio-x86 volumio[960]: info: Initializing BBC Radios Aug 23 12:48:05 volumio-x86 sudo[1487]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 23 12:48:05 volumio-x86 sudo[1487]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 12:48:05 volumio-x86 sudo[1487]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Aug 23 12:48:05 volumio-x86 sudo[1487]: pam_unix(sudo:session): session closed for user root Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 23 12:48:05 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 12:48:05 volumio-x86 volumio[960]: info: AutoStart - onStart Aug 23 12:48:05 volumio-x86 volumio[960]: info: Loading i18n strings for locale zh Aug 23 12:48:05 volumio-x86 volumio[960]: info: /tmp/myfifo created Aug 23 12:48:05 volumio-x86 volumio[960]: info: /tmp/myfifosa created Aug 23 12:48:06 volumio-x86 sudo[1508]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/modprobe snd-dummy index=7 pcm_substreams=1 fake_buffer=0 Aug 23 12:48:06 volumio-x86 sudo[1508]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 12:48:06 volumio-x86 ntpd[1417]: Soliciting pool server 47.243.51.23 Aug 23 12:48:06 volumio-x86 sudo[1508]: pam_unix(sudo:session): session closed for user root Aug 23 12:48:06 volumio-x86 volumio[960]: info: snd-dummy loaded Aug 23 12:48:06 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 12:48:06 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:06 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , startShairportSync Aug 23 12:48:06 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:06 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 12:48:06 volumio-x86 sudo[1529]: 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 Aug 23 12:48:06 volumio-x86 volumio[960]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 23 12:48:06 volumio-x86 sudo[1529]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 12:48:06 volumio-x86 sudo[1529]: pam_unix(sudo:session): session closed for user root Aug 23 12:48:06 volumio-x86 volumio[960]: info: Volumio Calling Home Aug 23 12:48:06 volumio-x86 volumio[960]: info: MPD Permissions set Aug 23 12:48:06 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetState Aug 23 12:48:06 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:06 volumio-x86 volumio[960]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Aug 23 12:48:06 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:06 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:06 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:06 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:06 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:06 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 12:48:06 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Aug 23 12:48:06 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:06 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:06 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:06 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:06 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:06 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:06 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:06 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:06 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:06 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 12:48:06 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Aug 23 12:48:06 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:06 volumio-x86 volumio[960]: info: Discovery: adding 337f3cc6-b129-4bb4-afa6-c01f9e7029fa Aug 23 12:48:06 volumio-x86 volumio[960]: info: Discovery: Found device Volumio-x86 Aug 23 12:48:06 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetState Aug 23 12:48:06 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:06 volumio-x86 volumio[960]: info: Starting Shairport Sync Aug 23 12:48:06 volumio-x86 sudo[1551]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount --bind /tmp/mpd.conf.tmpl /volumio/app/plugins/music_service/mpd/mpd.conf.tmpl Aug 23 12:48:06 volumio-x86 sudo[1551]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 12:48:06 volumio-x86 volumio[960]: info: Starting Shairport Sync Aug 23 12:48:06 volumio-x86 volumio[960]: info: Starting Shairport Sync Aug 23 12:48:06 volumio-x86 sudo[1554]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 23 12:48:06 volumio-x86 sudo[1554]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 12:48:06 volumio-x86 sudo[1551]: pam_unix(sudo:session): session closed for user root Aug 23 12:48:06 volumio-x86 volumio[960]: info: Starting Shairport Sync Aug 23 12:48:06 volumio-x86 sudo[1556]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 23 12:48:06 volumio-x86 sudo[1556]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 12:48:06 volumio-x86 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Aug 23 12:48:06 volumio-x86 systemd[1]: shairport-sync.service: Succeeded. Aug 23 12:48:06 volumio-x86 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Aug 23 12:48:06 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetState Aug 23 12:48:06 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:06 volumio-x86 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Aug 23 12:48:06 volumio-x86 sudo[1559]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 23 12:48:06 volumio-x86 sudo[1559]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 12:48:06 volumio-x86 sudo[1554]: pam_unix(sudo:session): session closed for user root Aug 23 12:48:06 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: mpd , createMPDFile Aug 23 12:48:06 volumio-x86 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Aug 23 12:48:06 volumio-x86 systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Aug 23 12:48:06 volumio-x86 systemd[1]: shairport-sync.service: Succeeded. Aug 23 12:48:06 volumio-x86 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Aug 23 12:48:06 volumio-x86 sudo[1562]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 23 12:48:06 volumio-x86 sudo[1562]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 12:48:06 volumio-x86 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Aug 23 12:48:07 volumio-x86 ntpd[1417]: Soliciting pool server 162.159.200.123 Aug 23 12:48:07 volumio-x86 sudo[1556]: pam_unix(sudo:session): session closed for user root Aug 23 12:48:07 volumio-x86 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Aug 23 12:48:07 volumio-x86 systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Aug 23 12:48:07 volumio-x86 systemd[1]: shairport-sync.service: Succeeded. Aug 23 12:48:07 volumio-x86 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Aug 23 12:48:07 volumio-x86 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Aug 23 12:48:07 volumio-x86 sudo[1559]: pam_unix(sudo:session): session closed for user root Aug 23 12:48:07 volumio-x86 sudo[1562]: pam_unix(sudo:session): session closed for user root Aug 23 12:48:07 volumio-x86 sudo[1568]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 23 12:48:07 volumio-x86 sudo[1568]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 12:48:07 volumio-x86 sudo[1568]: pam_unix(sudo:session): session closed for user root Aug 23 12:48:07 volumio-x86 volumio[960]: info: Shairport-Sync Started Aug 23 12:48:07 volumio-x86 volumio[960]: Error adding Membership: Error: addMembership EINVAL Aug 23 12:48:07 volumio-x86 volumio[960]: info: Shairport-Sync Started Aug 23 12:48:07 volumio-x86 volumio[960]: info: Volumio called home Aug 23 12:48:07 volumio-x86 volumio[960]: info: MPD Permissions set Aug 23 12:48:07 volumio-x86 volumio[960]: info: Shairport-Sync Started Aug 23 12:48:07 volumio-x86 volumio[960]: info: Shairport-Sync Started Aug 23 12:48:07 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:07 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:07 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:07 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:07 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:07 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:07 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:07 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:07 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 12:48:07 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Aug 23 12:48:07 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:07 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Aug 23 12:48:07 volumio-x86 sudo[1580]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 23 12:48:07 volumio-x86 sudo[1580]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 12:48:07 volumio-x86 systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Aug 23 12:48:07 volumio-x86 systemd[1]: mpd.service: Succeeded. Aug 23 12:48:07 volumio-x86 systemd[1]: Stopped Music Player Daemon. Aug 23 12:48:07 volumio-x86 systemd[1]: Starting Music Player Daemon... Aug 23 12:48:07 volumio-x86 sudo[1582]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 23 12:48:07 volumio-x86 sudo[1582]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 12:48:07 volumio-x86 sudo[1582]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Aug 23 12:48:07 volumio-x86 sudo[1582]: pam_unix(sudo:session): session closed for user root Aug 23 12:48:07 volumio-x86 ntpd[1417]: Soliciting pool server 162.159.200.1 Aug 23 12:48:08 volumio-x86 ntpd[1417]: Soliciting pool server 119.28.230.190 Aug 23 12:48:08 volumio-x86 ntpd[1417]: Soliciting pool server 47.243.51.23 Aug 23 12:48:08 volumio-x86 ntpd[1417]: Soliciting pool server 47.243.51.23 Aug 23 12:48:08 volumio-x86 volumio[960]: 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: 3 Aug 23 12:48:08 volumio-x86 ntpd[1417]: Soliciting pool server 47.243.51.23 Aug 23 12:48:09 volumio-x86 mpd[1584]: Aug 23 12:48 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 23 12:48:09 volumio-x86 systemd[1]: Started Music Player Daemon. Aug 23 12:48:09 volumio-x86 sudo[1481]: pam_unix(sudo:session): session closed for user root Aug 23 12:48:09 volumio-x86 sudo[1580]: pam_unix(sudo:session): session closed for user root Aug 23 12:48:09 volumio-x86 sudo[1471]: pam_unix(sudo:session): session closed for user root Aug 23 12:48:09 volumio-x86 volumio[960]: info: Completed starting Core Plugins Aug 23 12:48:09 volumio-x86 volumio[960]: info: ------------------------------------------- Aug 23 12:48:09 volumio-x86 volumio[960]: info: ----- MyVolumio plugins startup ---- Aug 23 12:48:09 volumio-x86 volumio[960]: info: ------------------------------------------- Aug 23 12:48:09 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 23 12:48:09 volumio-x86 volumio[960]: error: MPD error: The expression evaluated to a falsy value: Aug 23 12:48:09 volumio-x86 volumio[960]: assert.ok(self.idling) Aug 23 12:48:09 volumio-x86 volumio[960]: error: The expression evaluated to a falsy value: Aug 23 12:48:09 volumio-x86 volumio[960]: assert.ok(self.idling) Aug 23 12:48:09 volumio-x86 volumio[960]: error: MPD error: The expression evaluated to a falsy value: Aug 23 12:48:09 volumio-x86 volumio[960]: assert.ok(self.idling) Aug 23 12:48:09 volumio-x86 volumio[960]: error: The expression evaluated to a falsy value: Aug 23 12:48:09 volumio-x86 volumio[960]: assert.ok(self.idling) Aug 23 12:48:09 volumio-x86 volumio[960]: info: MPD running with PID1584 Aug 23 12:48:09 volumio-x86 volumio[960]: ,establishing connection Aug 23 12:48:09 volumio-x86 volumio[960]: error: updateQueue error: null Aug 23 12:48:09 volumio-x86 volumio[960]: error: updateQueue error: null Aug 23 12:48:09 volumio-x86 nmbd[912]: [2024/08/23 12:48:09.419961, 0] ../lib/util/become_daemon.c:138(daemon_ready) Aug 23 12:48:09 volumio-x86 nmbd[912]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Aug 23 12:48:09 volumio-x86 systemd[1]: Started Samba NMB Daemon. Aug 23 12:48:09 volumio-x86 systemd[1]: Starting Samba Winbind Daemon... Aug 23 12:48:09 volumio-x86 winbindd[1591]: [2024/08/23 12:48:09.677849, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Aug 23 12:48:09 volumio-x86 winbindd[1591]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Aug 23 12:48:09 volumio-x86 winbindd[1591]: [2024/08/23 12:48:09.688271, 0] ../lib/util/become_daemon.c:138(daemon_ready) Aug 23 12:48:09 volumio-x86 winbindd[1591]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Aug 23 12:48:09 volumio-x86 systemd[1]: Started Samba Winbind Daemon. Aug 23 12:48:09 volumio-x86 systemd[1]: Starting Samba SMB Daemon... Aug 23 12:48:10 volumio-x86 smbd[1596]: [2024/08/23 12:48:10.134370, 0] ../lib/util/become_daemon.c:138(daemon_ready) Aug 23 12:48:10 volumio-x86 smbd[1596]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Aug 23 12:48:10 volumio-x86 systemd[1]: Started Samba SMB Daemon. Aug 23 12:48:10 volumio-x86 systemd[1]: Reached target Multi-User System. Aug 23 12:48:10 volumio-x86 systemd[1]: Reached target Graphical Interface. Aug 23 12:48:10 volumio-x86 systemd[1]: Starting Update UTMP about System Runlevel Changes... Aug 23 12:48:10 volumio-x86 systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Aug 23 12:48:10 volumio-x86 systemd[1]: Started Update UTMP about System Runlevel Changes. Aug 23 12:48:10 volumio-x86 systemd[1]: Startup finished in 9.359s (firmware) + 8.562s (loader) + 10.241s (kernel) + 20.875s (userspace) = 49.038s. Aug 23 12:48:10 volumio-x86 sudo[1606]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //127.0.0.1/Internal Storage/musics /mnt/NAS/local Aug 23 12:48:10 volumio-x86 sudo[1606]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 12:48:10 volumio-x86 kernel: CIFS: Attempting to mount //127.0.0.1/Internal Storage/musics Aug 23 12:48:10 volumio-x86 sudo[1606]: pam_unix(sudo:session): session closed for user root Aug 23 12:48:10 volumio-x86 volumio[960]: 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: 4 Aug 23 12:48:11 volumio-x86 sudo[1623]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 23 12:48:11 volumio-x86 sudo[1623]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 12:48:11 volumio-x86 sudo[1623]: pam_unix(sudo:session): session closed for user root Aug 23 12:48:11 volumio-x86 volumio-remote-updater[735]: [2024-08-23 12:48:11] [connect] Successful connection Aug 23 12:48:11 volumio-x86 sudo[1625]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 23 12:48:11 volumio-x86 sudo[1625]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 12:48:11 volumio-x86 volumio-remote-updater[735]: [2024-08-23 12:48:11] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1724388491 101 Aug 23 12:48:11 volumio-x86 volumio[960]: 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: 5 Aug 23 12:48:11 volumio-x86 sudo[1625]: pam_unix(sudo:session): session closed for user root Aug 23 12:48:11 volumio-x86 sudo[1631]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 23 12:48:11 volumio-x86 sudo[1631]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 12:48:11 volumio-x86 systemd[1]: Started UPnP Renderer front-end to MPD. Aug 23 12:48:11 volumio-x86 sudo[1631]: pam_unix(sudo:session): session closed for user root Aug 23 12:48:11 volumio-x86 volumio[960]: info: Upmpdcli Daemon Started Aug 23 12:48:11 volumio-x86 volumio[1634]: Generating RSA private key, 4096 bit long modulus (2 primes) Aug 23 12:48:12 volumio-x86 volumio[960]: 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 Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetVisibleSources Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetState Aug 23 12:48:12 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 23 12:48:12 volumio-x86 volumio[960]: info: Received Get System Info Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 23 12:48:12 volumio-x86 volumio[960]: info: Discovery: Getting this device information Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetState Aug 23 12:48:12 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetState Aug 23 12:48:12 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:12 volumio-x86 volumio[960]: info: Listing playlists Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetState Aug 23 12:48:12 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 23 12:48:12 volumio-x86 volumio[960]: info: Received Get System Info Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 23 12:48:12 volumio-x86 volumio[960]: info: Discovery: Getting this device information Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetState Aug 23 12:48:12 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetVisibleSources Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetState Aug 23 12:48:12 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetState Aug 23 12:48:12 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 23 12:48:12 volumio-x86 volumio[960]: info: Received Get System Info Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 23 12:48:12 volumio-x86 volumio[960]: info: Discovery: Getting this device information Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetState Aug 23 12:48:12 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 23 12:48:12 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetState Aug 23 12:48:12 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:12 volumio-x86 volumio[960]: info: Listing playlists Aug 23 12:48:14 volumio-x86 volumio[960]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 23 12:48:14 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Aug 23 12:48:15 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 23 12:48:15 volumio-x86 volumio[960]: info: Received Get System Info Aug 23 12:48:15 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 23 12:48:15 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 23 12:48:15 volumio-x86 volumio[960]: info: Discovery: Getting this device information Aug 23 12:48:15 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetState Aug 23 12:48:15 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:15 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 23 12:48:16 volumio-x86 volumio[1634]: ..........................................................................................................................................................................++++ Aug 23 12:48:16 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Aug 23 12:48:16 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetState Aug 23 12:48:16 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:18 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 23 12:48:18 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 23 12:48:18 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 23 12:48:18 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 23 12:48:18 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 23 12:48:18 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 23 12:48:18 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 23 12:48:18 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 23 12:48:18 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 23 12:48:18 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 23 12:48:18 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 23 12:48:18 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 23 12:48:18 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 23 12:48:18 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 23 12:48:18 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 23 12:48:18 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 23 12:48:18 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 23 12:48:18 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 23 12:48:18 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 23 12:48:18 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 23 12:48:18 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 23 12:48:18 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 23 12:48:18 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 23 12:48:18 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 23 12:48:18 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 23 12:48:18 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 23 12:48:18 volumio-x86 volumio[960]: info: Adding plugin bluetooth to MyMusic Plugins Aug 23 12:48:18 volumio-x86 volumio[960]: info: Adding plugin multiroom to MyMusic Plugins Aug 23 12:48:18 volumio-x86 volumio[960]: info: Adding plugin metavolumio to MyMusic Plugins Aug 23 12:48:18 volumio-x86 volumio[960]: info: Adding plugin cd_controller to MyMusic Plugins Aug 23 12:48:18 volumio-x86 volumio[960]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 23 12:48:18 volumio-x86 volumio[960]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 23 12:48:18 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 23 12:48:18 volumio-x86 sshd[1826]: Accepted password for volumio from 192.168.5.132 port 45544 ssh2 Aug 23 12:48:18 volumio-x86 sshd[1826]: pam_unix(sshd:session): session opened for user volumio by (uid=0) Aug 23 12:48:18 volumio-x86 systemd[1]: Created slice User Slice of UID 1000. Aug 23 12:48:18 volumio-x86 systemd[1]: Starting User Runtime Directory /run/user/1000... Aug 23 12:48:18 volumio-x86 systemd-logind[737]: New session 1 of user volumio. Aug 23 12:48:18 volumio-x86 systemd[1]: Started User Runtime Directory /run/user/1000. Aug 23 12:48:18 volumio-x86 systemd[1]: Starting User Manager for UID 1000... Aug 23 12:48:18 volumio-x86 systemd[1836]: pam_unix(systemd-user:session): session opened for user volumio by (uid=0) Aug 23 12:48:19 volumio-x86 systemd[1836]: Listening on Sound System. Aug 23 12:48:19 volumio-x86 systemd[1836]: Listening on GnuPG network certificate management daemon. Aug 23 12:48:19 volumio-x86 systemd[1836]: Listening on GnuPG cryptographic agent (ssh-agent emulation). Aug 23 12:48:19 volumio-x86 systemd[1836]: Reached target Paths. Aug 23 12:48:19 volumio-x86 systemd[1836]: Listening on GnuPG cryptographic agent and passphrase cache (restricted). Aug 23 12:48:19 volumio-x86 systemd[1836]: Starting D-Bus User Message Bus Socket. Aug 23 12:48:19 volumio-x86 systemd[1836]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers). Aug 23 12:48:19 volumio-x86 systemd[1836]: Reached target Timers. Aug 23 12:48:19 volumio-x86 systemd[1836]: Listening on GnuPG cryptographic agent and passphrase cache. Aug 23 12:48:19 volumio-x86 systemd[1836]: Listening on D-Bus User Message Bus Socket. Aug 23 12:48:19 volumio-x86 systemd[1836]: Reached target Sockets. Aug 23 12:48:19 volumio-x86 systemd[1836]: Reached target Basic System. Aug 23 12:48:19 volumio-x86 systemd[1]: Started User Manager for UID 1000. Aug 23 12:48:19 volumio-x86 systemd[1836]: Starting Music Player Daemon... Aug 23 12:48:19 volumio-x86 systemd[1]: Started Session 1 of user volumio. Aug 23 12:48:19 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 23 12:48:19 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 23 12:48:19 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 12:48:19 volumio-x86 volumio[960]: info: Starting MyVolumio Remote Streaming Endpoints Aug 23 12:48:19 volumio-x86 volumio[960]: info: MyVolumio login type: Token Aug 23 12:48:19 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 23 12:48:19 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 23 12:48:20 volumio-x86 mpd[1847]: exception: failed to open log file "/var/log/mpd.log" (config line 8): Permission denied Aug 23 12:48:20 volumio-x86 systemd[1836]: mpd.service: Main process exited, code=exited, status=1/FAILURE Aug 23 12:48:20 volumio-x86 systemd[1836]: mpd.service: Failed with result 'exit-code'. Aug 23 12:48:20 volumio-x86 systemd[1836]: Failed to start Music Player Daemon. Aug 23 12:48:20 volumio-x86 systemd[1836]: Reached target Default. Aug 23 12:48:20 volumio-x86 systemd[1836]: Startup finished in 1.338s. Aug 23 12:48:20 volumio-x86 volumio[960]: info: Starting Streaming Service Transparent Proxy Aug 23 12:48:20 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 23 12:48:20 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 23 12:48:20 volumio-x86 volumio[960]: info: Streaming services startup Aug 23 12:48:20 volumio-x86 volumio[960]: info: Starting Streaming Daemon Aug 23 12:48:20 volumio-x86 sudo[1866]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 23 12:48:20 volumio-x86 sudo[1866]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 12:48:20 volumio-x86 volumio[960]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 23 12:48:20 volumio-x86 sudo[1866]: pam_unix(sudo:session): session closed for user root Aug 23 12:48:20 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 23 12:48:20 volumio-x86 volumio[960]: error: Cannot start Volumio Streaming Daemon Aug 23 12:48:20 volumio-x86 volumio[960]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 23 12:48:20 volumio-x86 volumio[960]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 23 12:48:20 volumio-x86 volumio[1634]: ............................................................................................................................................................................++++ Aug 23 12:48:20 volumio-x86 volumio[1634]: e is 65537 (0x010001) Aug 23 12:48:20 volumio-x86 volumio[1634]: writing RSA key Aug 23 12:48:21 volumio-x86 volumio[960]: STREAMING PROXY: Starting server on port 3245 Aug 23 12:48:21 volumio-x86 volumio[960]: Node JS runtime: 14 Aug 23 12:48:21 volumio-x86 volumio[960]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 23 12:48:22 volumio-x86 systemd[1]: systemd-fsckd.service: Succeeded. Aug 23 12:48:23 volumio-x86 volumio[960]: info: MyVolumio token set successfully Aug 23 12:48:23 volumio-x86 volumio[960]: info: MYVOLUMIO: Adding device Aug 23 12:48:23 volumio-x86 volumio[960]: info: MYVOLUMIO: Evaluating Server Aug 23 12:48:23 volumio-x86 volumio[960]: info: MyVolumio status changed Aug 23 12:48:23 volumio-x86 volumio[960]: info: Streaming services startup Aug 23 12:48:23 volumio-x86 volumio[960]: info: Starting Streaming Daemon Aug 23 12:48:23 volumio-x86 volumio[960]: info: Removing browser output: myVolumio user plan is not superstar Aug 23 12:48:23 volumio-x86 volumio[960]: info: Removing audio output: Aug 23 12:48:23 volumio-x86 volumio[960]: info: Stoppping Tunnel 1 Aug 23 12:48:23 volumio-x86 sudo[1906]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 23 12:48:23 volumio-x86 sudo[1906]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 12:48:23 volumio-x86 sudo[1906]: pam_unix(sudo:session): session closed for user root Aug 23 12:48:23 volumio-x86 sudo[1908]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Aug 23 12:48:23 volumio-x86 sudo[1908]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 12:48:23 volumio-x86 volumio[960]: error: Cannot start Volumio Streaming Daemon Aug 23 12:48:23 volumio-x86 volumio[960]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 23 12:48:23 volumio-x86 volumio[960]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 23 12:48:23 volumio-x86 sudo[1908]: pam_unix(sudo:session): session closed for user root Aug 23 12:48:23 volumio-x86 volumio[960]: info: Remote SSH Stopped Aug 23 12:48:25 volumio-x86 volumio[960]: info: AutoStart - Plugin is starting Aug 23 12:48:25 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetQueue Aug 23 12:48:25 volumio-x86 volumio[960]: info: CoreStateMachine::getQueue Aug 23 12:48:25 volumio-x86 volumio[960]: info: CorePlayQueue::getQueue Aug 23 12:48:25 volumio-x86 volumio[960]: info: AutoStart - start playing Aug 23 12:48:25 volumio-x86 volumio[960]: info: AutoStart - start playing with no specific position Aug 23 12:48:25 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPlay Aug 23 12:48:25 volumio-x86 volumio[960]: info: CoreStateMachine::play index 0 Aug 23 12:48:25 volumio-x86 volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 23 12:48:25 volumio-x86 volumio[960]: info: CoreStateMachine::stop Aug 23 12:48:25 volumio-x86 volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 23 12:48:25 volumio-x86 volumio[960]: info: CoreStateMachine::play index undefined Aug 23 12:48:25 volumio-x86 volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 23 12:48:25 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:25 volumio-x86 volumio[960]: info: CoreStateMachine::startPlaybackTimer Aug 23 12:48:25 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:25 volumio-x86 volumio[960]: verbose: ControllerMpd::clearAddPlayTracks NAS/local/张国荣《风再起时》LPCD45/01.倩女幽魂.wav Aug 23 12:48:25 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand stop Aug 23 12:48:25 volumio-x86 volumio[960]: info: sendMpdCommand stop took 2 milliseconds Aug 23 12:48:25 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand clear Aug 23 12:48:25 volumio-x86 volumio[960]: info: Aug 23 12:48:25 volumio-x86 volumio[960]: ---------------------------- MPD announces system playlist update Aug 23 12:48:25 volumio-x86 volumio[960]: info: Ignoring MPD Status Update Aug 23 12:48:25 volumio-x86 volumio[960]: info: sendMpdCommand clear took 3 milliseconds Aug 23 12:48:25 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand add "NAS/local/张国荣《风再起时》LPCD45/01.倩女幽魂.wav" Aug 23 12:48:25 volumio-x86 volumio[960]: info: Aug 23 12:48:25 volumio-x86 volumio[960]: ---------------------------- MPD announces system playlist update Aug 23 12:48:25 volumio-x86 volumio[960]: info: Ignoring MPD Status Update Aug 23 12:48:25 volumio-x86 volumio[960]: info: Aug 23 12:48:25 volumio-x86 volumio[960]: ---------------------------- MPD announces system playlist update Aug 23 12:48:25 volumio-x86 volumio[960]: info: Ignoring MPD Status Update Aug 23 12:48:25 volumio-x86 volumio[960]: info: Aug 23 12:48:25 volumio-x86 volumio[960]: ---------------------------- MPD announces system playlist update Aug 23 12:48:25 volumio-x86 volumio[960]: info: Ignoring MPD Status Update Aug 23 12:48:25 volumio-x86 volumio[960]: error: updateQueue error: null Aug 23 12:48:25 volumio-x86 volumio[960]: info: Aug 23 12:48:25 volumio-x86 volumio[960]: ---------------------------- MPD announces system playlist update Aug 23 12:48:25 volumio-x86 volumio[960]: info: Ignoring MPD Status Update Aug 23 12:48:25 volumio-x86 volumio[960]: info: ------------------------------ 9ms Aug 23 12:48:25 volumio-x86 volumio[960]: info: sendMpdCommand add "NAS/local/张国荣《风再起时》LPCD45/01.倩女幽魂.wav" took 8 milliseconds Aug 23 12:48:25 volumio-x86 volumio[960]: info: ------------------------------ 7ms Aug 23 12:48:25 volumio-x86 volumio[960]: info: ------------------------------ 6ms Aug 23 12:48:25 volumio-x86 volumio[960]: info: ------------------------------ 5ms Aug 23 12:48:25 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand play Aug 23 12:48:25 volumio-x86 volumio[960]: info: Aug 23 12:48:25 volumio-x86 volumio[960]: ---------------------------- MPD announces system playlist update Aug 23 12:48:25 volumio-x86 volumio[960]: info: Ignoring MPD Status Update Aug 23 12:48:25 volumio-x86 volumio[960]: info: Aug 23 12:48:25 volumio-x86 volumio[960]: ---------------------------- MPD announces system playlist update Aug 23 12:48:25 volumio-x86 volumio[960]: info: Ignoring MPD Status Update Aug 23 12:48:25 volumio-x86 volumio[960]: info: Aug 23 12:48:25 volumio-x86 volumio[960]: ---------------------------- MPD announces system playlist update Aug 23 12:48:25 volumio-x86 volumio[960]: info: Ignoring MPD Status Update Aug 23 12:48:25 volumio-x86 volumio[960]: info: ------------------------------ 10ms Aug 23 12:48:25 volumio-x86 volumio[960]: info: sendMpdCommand play took 6 milliseconds Aug 23 12:48:25 volumio-x86 volumio[960]: info: ------------------------------ 5ms Aug 23 12:48:25 volumio-x86 volumio[960]: info: ------------------------------ 4ms Aug 23 12:48:25 volumio-x86 volumio[960]: info: ------------------------------ 4ms Aug 23 12:48:26 volumio-x86 volumio[960]: info: Aug 23 12:48:26 volumio-x86 volumio[960]: ---------------------------- MPD announces state update: player Aug 23 12:48:26 volumio-x86 volumio[960]: info: ControllerMpd::getState Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand status Aug 23 12:48:26 volumio-x86 volumio[960]: info: Aug 23 12:48:26 volumio-x86 volumio[960]: ---------------------------- MPD announces state update: player Aug 23 12:48:26 volumio-x86 volumio[960]: info: ControllerMpd::getState Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand status Aug 23 12:48:26 volumio-x86 volumio[960]: info: Aug 23 12:48:26 volumio-x86 volumio[960]: ---------------------------- MPD announces state update: player Aug 23 12:48:26 volumio-x86 volumio[960]: info: ControllerMpd::getState Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand status Aug 23 12:48:26 volumio-x86 volumio[960]: info: Aug 23 12:48:26 volumio-x86 volumio[960]: ---------------------------- MPD announces state update: player Aug 23 12:48:26 volumio-x86 volumio[960]: info: ControllerMpd::getState Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand status Aug 23 12:48:26 volumio-x86 kernel: intel_sst_acpi 808622A8:00: FW Version 01.0b.02.02 Aug 23 12:48:26 volumio-x86 volumio[960]: info: sendMpdCommand status took 355 milliseconds Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::parseState Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 12:48:26 volumio-x86 volumio[960]: info: Aug 23 12:48:26 volumio-x86 volumio[960]: ---------------------------- MPD announces state update: player Aug 23 12:48:26 volumio-x86 volumio[960]: info: ControllerMpd::getState Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand status Aug 23 12:48:26 volumio-x86 volumio[960]: info: sendMpdCommand status took 358 milliseconds Aug 23 12:48:26 volumio-x86 volumio[960]: info: sendMpdCommand status took 355 milliseconds Aug 23 12:48:26 volumio-x86 volumio[960]: info: sendMpdCommand status took 353 milliseconds Aug 23 12:48:26 volumio-x86 volumio[960]: info: sendMpdCommand playlistinfo took 4 milliseconds Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::parseState Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::parseState Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::parseState Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::parseTrackInfo Aug 23 12:48:26 volumio-x86 volumio[960]: info: ControllerMpd::pushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreCommandRouter::servicePushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":218,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"01.倩女幽魂.wav","artist":null,"album":null,"uri":"NAS/local/张国荣《风再起时》LPCD45/01.倩女幽魂.wav","trackType":"wav"} Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: CURRENT POSITION 0 Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::syncState stateService play Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::syncState currentStatus stop Aug 23 12:48:26 volumio-x86 volumio[960]: info: ------------------------------ 373ms Aug 23 12:48:26 volumio-x86 volumio[960]: info: Aug 23 12:48:26 volumio-x86 volumio[960]: ---------------------------- MPD announces state update: player Aug 23 12:48:26 volumio-x86 volumio[960]: info: ControllerMpd::getState Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand status Aug 23 12:48:26 volumio-x86 volumio[960]: info: Aug 23 12:48:26 volumio-x86 volumio[960]: ---------------------------- MPD announces state update: player Aug 23 12:48:26 volumio-x86 volumio[960]: info: ControllerMpd::getState Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand status Aug 23 12:48:26 volumio-x86 volumio[960]: info: Aug 23 12:48:26 volumio-x86 volumio[960]: ---------------------------- MPD announces state update: player Aug 23 12:48:26 volumio-x86 volumio[960]: info: ControllerMpd::getState Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand status Aug 23 12:48:26 volumio-x86 volumio[960]: info: sendMpdCommand status took 18 milliseconds Aug 23 12:48:26 volumio-x86 volumio[960]: info: sendMpdCommand playlistinfo took 15 milliseconds Aug 23 12:48:26 volumio-x86 volumio[960]: info: sendMpdCommand playlistinfo took 14 milliseconds Aug 23 12:48:26 volumio-x86 volumio[960]: info: sendMpdCommand playlistinfo took 15 milliseconds Aug 23 12:48:26 volumio-x86 volumio[960]: info: sendMpdCommand status took 5 milliseconds Aug 23 12:48:26 volumio-x86 volumio[960]: info: sendMpdCommand status took 4 milliseconds Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::parseState Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::parseTrackInfo Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::parseTrackInfo Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::parseTrackInfo Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::parseState Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::parseState Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 12:48:26 volumio-x86 volumio[960]: info: ControllerMpd::pushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreCommandRouter::servicePushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":341,"duration":218,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"01.倩女幽魂.wav","artist":null,"album":null,"uri":"NAS/local/张国荣《风再起时》LPCD45/01.倩女幽魂.wav","trackType":"wav"} Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: CURRENT POSITION 0 Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::syncState stateService play Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::syncState currentStatus play Aug 23 12:48:26 volumio-x86 volumio[960]: info: Received an update from plugin. extracting info from payload Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: ControllerMpd::pushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreCommandRouter::servicePushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":432,"duration":218,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"01.倩女幽魂.wav","artist":null,"album":null,"uri":"NAS/local/张国荣《风再起时》LPCD45/01.倩女幽魂.wav","trackType":"wav"} Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: CURRENT POSITION 0 Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::syncState stateService play Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::syncState currentStatus play Aug 23 12:48:26 volumio-x86 volumio[960]: info: Received an update from plugin. extracting info from payload Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: ControllerMpd::pushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreCommandRouter::servicePushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":432,"duration":218,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"01.倩女幽魂.wav","artist":null,"album":null,"uri":"NAS/local/张国荣《风再起时》LPCD45/01.倩女幽魂.wav","trackType":"wav"} Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: CURRENT POSITION 0 Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::syncState stateService play Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::syncState currentStatus play Aug 23 12:48:26 volumio-x86 volumio[960]: info: Received an update from plugin. extracting info from payload Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: ------------------------------ 426ms Aug 23 12:48:26 volumio-x86 volumio[960]: info: ------------------------------ 424ms Aug 23 12:48:26 volumio-x86 volumio[960]: info: ------------------------------ 423ms Aug 23 12:48:26 volumio-x86 volumio[960]: info: sendMpdCommand status took 55 milliseconds Aug 23 12:48:26 volumio-x86 volumio[960]: info: sendMpdCommand playlistinfo took 51 milliseconds Aug 23 12:48:26 volumio-x86 volumio[960]: info: sendMpdCommand playlistinfo took 50 milliseconds Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::parseState Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::parseTrackInfo Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::parseTrackInfo Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::parseTrackInfo Aug 23 12:48:26 volumio-x86 volumio[960]: info: ControllerMpd::pushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreCommandRouter::servicePushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":523,"duration":218,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"01.倩女幽魂.wav","artist":null,"album":null,"uri":"NAS/local/张国荣《风再起时》LPCD45/01.倩女幽魂.wav","trackType":"wav"} Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: CURRENT POSITION 0 Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::syncState stateService play Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::syncState currentStatus play Aug 23 12:48:26 volumio-x86 volumio[960]: info: Received an update from plugin. extracting info from payload Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: ControllerMpd::pushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreCommandRouter::servicePushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":705,"duration":218,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"01.倩女幽魂.wav","artist":null,"album":null,"uri":"NAS/local/张国荣《风再起时》LPCD45/01.倩女幽魂.wav","trackType":"wav"} Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: CURRENT POSITION 0 Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::syncState stateService play Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::syncState currentStatus play Aug 23 12:48:26 volumio-x86 volumio[960]: info: Received an update from plugin. extracting info from payload Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: ControllerMpd::pushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreCommandRouter::servicePushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":705,"duration":218,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"01.倩女幽魂.wav","artist":null,"album":null,"uri":"NAS/local/张国荣《风再起时》LPCD45/01.倩女幽魂.wav","trackType":"wav"} Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: CURRENT POSITION 0 Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::syncState stateService play Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::syncState currentStatus play Aug 23 12:48:26 volumio-x86 volumio[960]: info: Received an update from plugin. extracting info from payload Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: ------------------------------ 124ms Aug 23 12:48:26 volumio-x86 volumio[960]: info: ------------------------------ 111ms Aug 23 12:48:26 volumio-x86 volumio[960]: info: ------------------------------ 111ms Aug 23 12:48:26 volumio-x86 volumio[960]: info: sendMpdCommand playlistinfo took 96 milliseconds Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: ControllerMpd::parseTrackInfo Aug 23 12:48:26 volumio-x86 volumio[960]: info: ControllerMpd::pushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreCommandRouter::servicePushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":705,"duration":218,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"01.倩女幽魂.wav","artist":null,"album":null,"uri":"NAS/local/张国荣《风再起时》LPCD45/01.倩女幽魂.wav","trackType":"wav"} Aug 23 12:48:26 volumio-x86 volumio[960]: verbose: CURRENT POSITION 0 Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::syncState stateService play Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::syncState currentStatus play Aug 23 12:48:26 volumio-x86 volumio[960]: info: Received an update from plugin. extracting info from payload Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:26 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:48:26 volumio-x86 volumio[960]: info: ------------------------------ 176ms Aug 23 12:48:27 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetState Aug 23 12:48:27 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:27 volumio-x86 sudo[1932]: root : TTY=unknown ; PWD=/data/plugins/user_interface/peppy_screensaver ; USER=root ; COMMAND=/usr/bin/python3 ./screensaver/volumio_peppymeter.py Aug 23 12:48:27 volumio-x86 sudo[1932]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 23 12:48:29 volumio-x86 volumio[960]: info: Setting Geolocation for MyVolumio to as2 Aug 23 12:48:29 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 12:48:29 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 12:48:29 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 12:48:30 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 23 12:48:30 volumio-x86 volumio[960]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Aug 23 12:48:30 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Aug 23 12:48:30 volumio-x86 volumio[960]: info: Received Get System Version Aug 23 12:48:30 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 23 12:48:30 volumio-x86 volumio[960]: info: Received Get System Info Aug 23 12:48:30 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 23 12:48:30 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 23 12:48:30 volumio-x86 volumio[960]: info: Discovery: Getting this device information Aug 23 12:48:30 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetState Aug 23 12:48:30 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:30 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 23 12:48:30 volumio-x86 volumio[960]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 23 12:48:30 volumio-x86 volumio[960]: info: Updating MyVolumio device info Aug 23 12:48:30 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 12:48:30 volumio-x86 volumio[960]: 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: 7 Aug 23 12:48:30 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetState Aug 23 12:48:30 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:31 volumio-x86 volumio[960]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 23 12:48:31 volumio-x86 volumio[960]: 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: 8 Aug 23 12:48:31 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetState Aug 23 12:48:31 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:33 volumio-x86 kernel: smbd(1612): Attempt to set a LOCK_MAND lock via flock(2). This support has been removed and the request ignored. Aug 23 12:48:33 volumio-x86 systemd[1]: systemd-hostnamed.service: Succeeded. Aug 23 12:48:34 volumio-x86 volumio[960]: info: MYVOLUMIO: Adding device Aug 23 12:48:34 volumio-x86 volumio[960]: info: MYVOLUMIO: Evaluating Server Aug 23 12:48:34 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 23 12:48:34 volumio-x86 volumio[960]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Aug 23 12:48:34 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetState Aug 23 12:48:34 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:48:36 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 23 12:48:36 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 12:48:36 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 23 12:48:36 volumio-x86 volumio-remote-updater[735]: No test mode Aug 23 12:48:36 volumio-x86 volumio-remote-updater[735]: No alpha test mode Aug 23 12:48:36 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Aug 23 12:48:37 volumio-x86 volumio[960]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Aug 23 12:48:37 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Aug 23 12:48:39 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:39 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:39 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 23 12:48:39 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Aug 23 12:48:39 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 23 12:48:39 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetBrowseSources Aug 23 12:48:39 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 23 12:48:40 volumio-x86 volumio[960]: info: Setting Geolocation for MyVolumio to as2 Aug 23 12:48:40 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 12:48:40 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 12:48:40 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 12:48:40 volumio-x86 volumio[960]: error: MyVolumio Plugin failed to authenticate in a timely fashion Aug 23 12:48:40 volumio-x86 volumio[960]: info: Completed starting MyVolumio Plugin Aug 23 12:48:40 volumio-x86 volumio[960]: info: BOOT COMPLETED Aug 23 12:48:40 volumio-x86 volumio[960]: [Metrics] CommandRouter: 43s 789.24ms Aug 23 12:48:40 volumio-x86 volumio[960]: info: CoreCommandRouter::volumiosetStartupVolume Aug 23 12:48:40 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 23 12:48:40 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 12:48:40 volumio-x86 volumio[960]: info: CoreCommandRouter::Close All Modals sent Aug 23 12:48:40 volumio-x86 volumio[960]: info: CoreCommandRouter::Close All Modals sent Aug 23 12:48:40 volumio-x86 volumio[960]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav Aug 23 12:48:40 volumio-x86 volumio[960]: aplay: main:828: audio open error: Device or resource busy Aug 23 12:48:40 volumio-x86 volumio[960]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 23 12:48:41 volumio-x86 volumio[960]: info: Updating MyVolumio device info Aug 23 12:48:41 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 12:48:41 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 23 12:48:41 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Aug 23 12:48:41 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 23 12:48:41 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Aug 23 12:48:41 volumio-x86 volumio[960]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 23 12:49:17 volumio-x86 ntpd[1417]: Soliciting pool server 2606:4700:f1::123 Aug 23 12:49:25 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 23 12:49:25 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 23 12:49:25 volumio-x86 volumio[960]: info: Discovery: Getting this device information Aug 23 12:49:25 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetState Aug 23 12:49:25 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:49:25 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 23 12:49:26 volumio-x86 volumio[960]: verbose: New Socket.io Connection to 192.168.5.181 from 192.168.5.116 UA: Mozilla/5.0 (Linux; Android 14; Pixel 7 Pro Build/AP2A.240605.024; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/127.0.6533.103 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Aug 23 12:49:26 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 23 12:49:26 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetVisibleSources Aug 23 12:49:26 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 23 12:49:26 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetState Aug 23 12:49:26 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:49:26 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 23 12:49:26 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 23 12:49:26 volumio-x86 volumio[960]: info: Received Get System Info Aug 23 12:49:26 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 23 12:49:26 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 23 12:49:26 volumio-x86 volumio[960]: info: Discovery: Getting this device information Aug 23 12:49:26 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetState Aug 23 12:49:26 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:49:26 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 23 12:49:26 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetState Aug 23 12:49:26 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:49:26 volumio-x86 volumio[960]: info: Listing playlists Aug 23 12:49:26 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetQueue Aug 23 12:49:26 volumio-x86 volumio[960]: info: CoreStateMachine::getQueue Aug 23 12:49:26 volumio-x86 volumio[960]: info: CorePlayQueue::getQueue Aug 23 12:49:26 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 23 12:49:28 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioNext Aug 23 12:49:28 volumio-x86 volumio[960]: info: CoreStateMachine::next Aug 23 12:49:28 volumio-x86 volumio[960]: info: CoreStateMachine::stop Aug 23 12:49:28 volumio-x86 volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 23 12:49:28 volumio-x86 volumio[960]: info: CoreStateMachine::stPlaybackTimer Aug 23 12:49:28 volumio-x86 volumio[960]: info: CoreStateMachine::updateTrackBlock Aug 23 12:49:28 volumio-x86 volumio[960]: info: CorePlayQueue::getTrackBlock Aug 23 12:49:28 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:49:28 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:49:28 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 23 12:49:28 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:49:28 volumio-x86 volumio[960]: info: CoreStateMachine::serviceStop Aug 23 12:49:28 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 0 Aug 23 12:49:28 volumio-x86 volumio[960]: info: CoreCommandRouter::serviceStop Aug 23 12:49:28 volumio-x86 volumio[960]: info: ControllerMpd::stop Aug 23 12:49:28 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand stop Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand stop took 160 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::play index undefined Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 23 12:49:29 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::startPlaybackTimer Aug 23 12:49:29 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::clearAddPlayTracks NAS/local/张国荣《风再起时》LPCD45/02.拒绝再玩.wav Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand stop Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::updateTrackBlock Aug 23 12:49:29 volumio-x86 volumio[960]: info: CorePlayQueue::getTrackBlock Aug 23 12:49:29 volumio-x86 volumio[960]: info: Aug 23 12:49:29 volumio-x86 volumio[960]: ---------------------------- MPD announces state update: player Aug 23 12:49:29 volumio-x86 volumio[960]: info: ControllerMpd::getState Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand status Aug 23 12:49:29 volumio-x86 volumio[960]: info: Aug 23 12:49:29 volumio-x86 volumio[960]: ---------------------------- MPD announces state update: player Aug 23 12:49:29 volumio-x86 volumio[960]: info: ControllerMpd::getState Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand status Aug 23 12:49:29 volumio-x86 volumio[960]: info: Aug 23 12:49:29 volumio-x86 volumio[960]: ---------------------------- MPD announces state update: player Aug 23 12:49:29 volumio-x86 volumio[960]: info: ControllerMpd::getState Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand status Aug 23 12:49:29 volumio-x86 volumio[960]: info: Aug 23 12:49:29 volumio-x86 volumio[960]: ---------------------------- MPD announces state update: player Aug 23 12:49:29 volumio-x86 volumio[960]: info: ControllerMpd::getState Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand status Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand stop took 14 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand status took 10 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand status took 9 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand clear Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::parseState Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::parseState Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 12:49:29 volumio-x86 volumio[960]: info: Aug 23 12:49:29 volumio-x86 volumio[960]: ---------------------------- MPD announces system playlist update Aug 23 12:49:29 volumio-x86 volumio[960]: info: Ignoring MPD Status Update Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand status took 15 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand status took 11 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand clear took 9 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand playlistinfo took 8 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand playlistinfo took 9 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::parseState Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::parseState Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand add "NAS/local/张国荣《风再起时》LPCD45/02.拒绝再玩.wav" Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::parseTrackInfo Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::parseTrackInfo Aug 23 12:49:29 volumio-x86 volumio[960]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Aug 23 12:49:29 volumio-x86 volumio[960]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Aug 23 12:49:29 volumio-x86 volumio[960]: info: ------------------------------ 33ms Aug 23 12:49:29 volumio-x86 volumio[960]: info: ------------------------------ 31ms Aug 23 12:49:29 volumio-x86 volumio[960]: info: Aug 23 12:49:29 volumio-x86 volumio[960]: ---------------------------- MPD announces system playlist update Aug 23 12:49:29 volumio-x86 volumio[960]: info: Ignoring MPD Status Update Aug 23 12:49:29 volumio-x86 volumio[960]: info: Aug 23 12:49:29 volumio-x86 volumio[960]: ---------------------------- MPD announces system playlist update Aug 23 12:49:29 volumio-x86 volumio[960]: info: Ignoring MPD Status Update Aug 23 12:49:29 volumio-x86 volumio[960]: info: Aug 23 12:49:29 volumio-x86 volumio[960]: ---------------------------- MPD announces system playlist update Aug 23 12:49:29 volumio-x86 volumio[960]: info: Ignoring MPD Status Update Aug 23 12:49:29 volumio-x86 volumio[960]: error: updateQueue error: null Aug 23 12:49:29 volumio-x86 volumio[960]: info: Aug 23 12:49:29 volumio-x86 volumio[960]: ---------------------------- MPD announces system playlist update Aug 23 12:49:29 volumio-x86 volumio[960]: info: Ignoring MPD Status Update Aug 23 12:49:29 volumio-x86 volumio[960]: info: ------------------------------ 28ms Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand playlistinfo took 21 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand playlistinfo took 22 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand add "NAS/local/张国荣《风再起时》LPCD45/02.拒绝再玩.wav" took 21 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: info: ------------------------------ 15ms Aug 23 12:49:29 volumio-x86 volumio[960]: info: ------------------------------ 14ms Aug 23 12:49:29 volumio-x86 volumio[960]: info: ------------------------------ 12ms Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::parseTrackInfo Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::parseTrackInfo Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand play Aug 23 12:49:29 volumio-x86 volumio[960]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Aug 23 12:49:29 volumio-x86 volumio[960]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Aug 23 12:49:29 volumio-x86 volumio[960]: info: ------------------------------ 49ms Aug 23 12:49:29 volumio-x86 volumio[960]: info: ------------------------------ 45ms Aug 23 12:49:29 volumio-x86 volumio[960]: info: Aug 23 12:49:29 volumio-x86 volumio[960]: ---------------------------- MPD announces system playlist update Aug 23 12:49:29 volumio-x86 volumio[960]: info: Ignoring MPD Status Update Aug 23 12:49:29 volumio-x86 volumio[960]: info: Aug 23 12:49:29 volumio-x86 volumio[960]: ---------------------------- MPD announces system playlist update Aug 23 12:49:29 volumio-x86 volumio[960]: info: Ignoring MPD Status Update Aug 23 12:49:29 volumio-x86 volumio[960]: info: Aug 23 12:49:29 volumio-x86 volumio[960]: ---------------------------- MPD announces system playlist update Aug 23 12:49:29 volumio-x86 volumio[960]: info: Ignoring MPD Status Update Aug 23 12:49:29 volumio-x86 volumio[960]: info: ------------------------------ 21ms Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand play took 10 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: info: ------------------------------ 8ms Aug 23 12:49:29 volumio-x86 volumio[960]: info: ------------------------------ 6ms Aug 23 12:49:29 volumio-x86 volumio[960]: info: ------------------------------ 5ms Aug 23 12:49:29 volumio-x86 volumio[960]: info: Aug 23 12:49:29 volumio-x86 volumio[960]: ---------------------------- MPD announces state update: player Aug 23 12:49:29 volumio-x86 volumio[960]: info: ControllerMpd::getState Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand status Aug 23 12:49:29 volumio-x86 volumio[960]: info: Aug 23 12:49:29 volumio-x86 volumio[960]: ---------------------------- MPD announces state update: player Aug 23 12:49:29 volumio-x86 volumio[960]: info: ControllerMpd::getState Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand status Aug 23 12:49:29 volumio-x86 volumio[960]: info: Aug 23 12:49:29 volumio-x86 volumio[960]: ---------------------------- MPD announces state update: player Aug 23 12:49:29 volumio-x86 volumio[960]: info: ControllerMpd::getState Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand status Aug 23 12:49:29 volumio-x86 volumio[960]: info: Aug 23 12:49:29 volumio-x86 volumio[960]: ---------------------------- MPD announces state update: player Aug 23 12:49:29 volumio-x86 volumio[960]: info: ControllerMpd::getState Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand status Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand status took 151 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::parseState Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 12:49:29 volumio-x86 volumio[960]: info: Aug 23 12:49:29 volumio-x86 volumio[960]: ---------------------------- MPD announces state update: player Aug 23 12:49:29 volumio-x86 volumio[960]: info: ControllerMpd::getState Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand status Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand status took 153 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand status took 148 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand status took 146 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand playlistinfo took 4 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::parseState Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::parseState Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::parseState Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::parseTrackInfo Aug 23 12:49:29 volumio-x86 volumio[960]: info: ControllerMpd::pushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreCommandRouter::servicePushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":216,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"02.拒绝再玩.wav","artist":null,"album":null,"uri":"NAS/local/张国荣《风再起时》LPCD45/02.拒绝再玩.wav","trackType":"wav"} Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: CURRENT POSITION 1 Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::syncState stateService play Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::syncState currentStatus stop Aug 23 12:49:29 volumio-x86 volumio[960]: info: ------------------------------ 166ms Aug 23 12:49:29 volumio-x86 volumio[960]: info: Aug 23 12:49:29 volumio-x86 volumio[960]: ---------------------------- MPD announces state update: player Aug 23 12:49:29 volumio-x86 volumio[960]: info: ControllerMpd::getState Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand status Aug 23 12:49:29 volumio-x86 volumio[960]: info: Aug 23 12:49:29 volumio-x86 volumio[960]: ---------------------------- MPD announces state update: player Aug 23 12:49:29 volumio-x86 volumio[960]: info: ControllerMpd::getState Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand status Aug 23 12:49:29 volumio-x86 volumio[960]: info: Aug 23 12:49:29 volumio-x86 volumio[960]: ---------------------------- MPD announces state update: player Aug 23 12:49:29 volumio-x86 volumio[960]: info: ControllerMpd::getState Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand status Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand status took 16 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand playlistinfo took 15 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand playlistinfo took 14 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand playlistinfo took 15 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand status took 8 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand status took 5 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand status took 4 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::parseState Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::parseTrackInfo Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::parseTrackInfo Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::parseTrackInfo Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::parseState Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::parseState Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::parseState Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 12:49:29 volumio-x86 volumio[960]: info: ControllerMpd::pushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreCommandRouter::servicePushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":227,"duration":216,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"02.拒绝再玩.wav","artist":null,"album":null,"uri":"NAS/local/张国荣《风再起时》LPCD45/02.拒绝再玩.wav","trackType":"wav"} Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: CURRENT POSITION 1 Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::syncState stateService play Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::syncState currentStatus play Aug 23 12:49:29 volumio-x86 volumio[960]: info: Received an update from plugin. extracting info from payload Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: ControllerMpd::pushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreCommandRouter::servicePushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":250,"duration":216,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"02.拒绝再玩.wav","artist":null,"album":null,"uri":"NAS/local/张国荣《风再起时》LPCD45/02.拒绝再玩.wav","trackType":"wav"} Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: CURRENT POSITION 1 Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::syncState stateService play Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::syncState currentStatus play Aug 23 12:49:29 volumio-x86 volumio[960]: info: Received an update from plugin. extracting info from payload Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: ControllerMpd::pushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreCommandRouter::servicePushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":341,"duration":216,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"02.拒绝再玩.wav","artist":null,"album":null,"uri":"NAS/local/张国荣《风再起时》LPCD45/02.拒绝再玩.wav","trackType":"wav"} Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: CURRENT POSITION 1 Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::syncState stateService play Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::syncState currentStatus play Aug 23 12:49:29 volumio-x86 volumio[960]: info: Received an update from plugin. extracting info from payload Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: ------------------------------ 268ms Aug 23 12:49:29 volumio-x86 volumio[960]: info: ------------------------------ 264ms Aug 23 12:49:29 volumio-x86 volumio[960]: info: ------------------------------ 263ms Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand playlistinfo took 99 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand playlistinfo took 97 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand playlistinfo took 98 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: info: sendMpdCommand playlistinfo took 97 milliseconds Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::parseTrackInfo Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::parseTrackInfo Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::parseTrackInfo Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: ControllerMpd::parseTrackInfo Aug 23 12:49:29 volumio-x86 volumio[960]: info: ControllerMpd::pushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreCommandRouter::servicePushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":523,"duration":216,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"02.拒绝再玩.wav","artist":null,"album":null,"uri":"NAS/local/张国荣《风再起时》LPCD45/02.拒绝再玩.wav","trackType":"wav"} Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: CURRENT POSITION 1 Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::syncState stateService play Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::syncState currentStatus play Aug 23 12:49:29 volumio-x86 volumio[960]: info: Received an update from plugin. extracting info from payload Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: ControllerMpd::pushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreCommandRouter::servicePushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":614,"duration":216,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"02.拒绝再玩.wav","artist":null,"album":null,"uri":"NAS/local/张国荣《风再起时》LPCD45/02.拒绝再玩.wav","trackType":"wav"} Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: CURRENT POSITION 1 Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::syncState stateService play Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::syncState currentStatus play Aug 23 12:49:29 volumio-x86 volumio[960]: info: Received an update from plugin. extracting info from payload Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: ControllerMpd::pushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreCommandRouter::servicePushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":705,"duration":216,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"02.拒绝再玩.wav","artist":null,"album":null,"uri":"NAS/local/张国荣《风再起时》LPCD45/02.拒绝再玩.wav","trackType":"wav"} Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: CURRENT POSITION 1 Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::syncState stateService play Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::syncState currentStatus play Aug 23 12:49:29 volumio-x86 volumio[960]: info: Received an update from plugin. extracting info from payload Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: ControllerMpd::pushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreCommandRouter::servicePushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: STATE SERVICE {"status":"play","position":0,"seek":705,"duration":216,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"02.拒绝再玩.wav","artist":null,"album":null,"uri":"NAS/local/张国荣《风再起时》LPCD45/02.拒绝再玩.wav","trackType":"wav"} Aug 23 12:49:29 volumio-x86 volumio[960]: verbose: CURRENT POSITION 1 Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::syncState stateService play Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::syncState currentStatus play Aug 23 12:49:29 volumio-x86 volumio[960]: info: Received an update from plugin. extracting info from payload Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:29 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:49:29 volumio-x86 volumio[960]: info: ------------------------------ 237ms Aug 23 12:49:29 volumio-x86 volumio[960]: info: ------------------------------ 228ms Aug 23 12:49:29 volumio-x86 volumio[960]: info: ------------------------------ 228ms Aug 23 12:49:29 volumio-x86 volumio[960]: info: ------------------------------ 227ms Aug 23 12:49:39 volumio-x86 volumio[960]: 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: 8 Aug 23 12:49:39 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioGetState Aug 23 12:49:39 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPause Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreStateMachine::pause Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreStateMachine::stPlaybackTimer Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreStateMachine::servicePause Aug 23 12:49:46 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreCommandRouter::servicePause Aug 23 12:49:46 volumio-x86 volumio[960]: info: ControllerMpd::pause Aug 23 12:49:46 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand pause Aug 23 12:49:46 volumio-x86 volumio[960]: info: sendMpdCommand pause took 2 milliseconds Aug 23 12:49:46 volumio-x86 volumio[960]: info: Aug 23 12:49:46 volumio-x86 volumio[960]: ---------------------------- MPD announces state update: player Aug 23 12:49:46 volumio-x86 volumio[960]: info: ControllerMpd::getState Aug 23 12:49:46 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand status Aug 23 12:49:46 volumio-x86 volumio[960]: info: Aug 23 12:49:46 volumio-x86 volumio[960]: ---------------------------- MPD announces state update: player Aug 23 12:49:46 volumio-x86 volumio[960]: info: ControllerMpd::getState Aug 23 12:49:46 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand status Aug 23 12:49:46 volumio-x86 volumio[960]: info: Aug 23 12:49:46 volumio-x86 volumio[960]: ---------------------------- MPD announces state update: player Aug 23 12:49:46 volumio-x86 volumio[960]: info: ControllerMpd::getState Aug 23 12:49:46 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand status Aug 23 12:49:46 volumio-x86 volumio[960]: info: Aug 23 12:49:46 volumio-x86 volumio[960]: ---------------------------- MPD announces state update: player Aug 23 12:49:46 volumio-x86 volumio[960]: info: ControllerMpd::getState Aug 23 12:49:46 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand status Aug 23 12:49:46 volumio-x86 volumio[960]: info: sendMpdCommand status took 7 milliseconds Aug 23 12:49:46 volumio-x86 volumio[960]: info: sendMpdCommand status took 5 milliseconds Aug 23 12:49:46 volumio-x86 volumio[960]: info: sendMpdCommand status took 3 milliseconds Aug 23 12:49:46 volumio-x86 volumio[960]: info: sendMpdCommand status took 1 milliseconds Aug 23 12:49:46 volumio-x86 volumio[960]: verbose: ControllerMpd::parseState Aug 23 12:49:46 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 12:49:46 volumio-x86 volumio[960]: verbose: ControllerMpd::parseState Aug 23 12:49:46 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 12:49:46 volumio-x86 volumio[960]: verbose: ControllerMpd::parseState Aug 23 12:49:46 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 12:49:46 volumio-x86 volumio[960]: verbose: ControllerMpd::parseState Aug 23 12:49:46 volumio-x86 volumio[960]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 23 12:49:46 volumio-x86 volumio[960]: info: sendMpdCommand playlistinfo took 4 milliseconds Aug 23 12:49:46 volumio-x86 volumio[960]: info: sendMpdCommand playlistinfo took 3 milliseconds Aug 23 12:49:46 volumio-x86 volumio[960]: info: sendMpdCommand playlistinfo took 4 milliseconds Aug 23 12:49:46 volumio-x86 volumio[960]: verbose: ControllerMpd::parseTrackInfo Aug 23 12:49:46 volumio-x86 volumio[960]: verbose: ControllerMpd::parseTrackInfo Aug 23 12:49:46 volumio-x86 volumio[960]: info: ControllerMpd::pushState Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreCommandRouter::servicePushState Aug 23 12:49:46 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:46 volumio-x86 volumio[960]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":17985,"duration":216,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"02.拒绝再玩.wav","artist":null,"album":null,"uri":"NAS/local/张国荣《风再起时》LPCD45/02.拒绝再玩.wav","trackType":"wav"} Aug 23 12:49:46 volumio-x86 volumio[960]: verbose: CURRENT POSITION 1 Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreStateMachine::syncState stateService pause Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreStateMachine::syncState currentStatus pause Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:49:46 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreStateMachine::stPlaybackTimer Aug 23 12:49:46 volumio-x86 volumio[960]: info: ControllerMpd::pushState Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreCommandRouter::servicePushState Aug 23 12:49:46 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:46 volumio-x86 volumio[960]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":17985,"duration":216,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"02.拒绝再玩.wav","artist":null,"album":null,"uri":"NAS/local/张国荣《风再起时》LPCD45/02.拒绝再玩.wav","trackType":"wav"} Aug 23 12:49:46 volumio-x86 volumio[960]: verbose: CURRENT POSITION 1 Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreStateMachine::syncState stateService pause Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreStateMachine::syncState currentStatus pause Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:49:46 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreStateMachine::stPlaybackTimer Aug 23 12:49:46 volumio-x86 volumio[960]: info: ControllerMpd::pushState Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreCommandRouter::servicePushState Aug 23 12:49:46 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:46 volumio-x86 volumio[960]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":17985,"duration":216,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"02.拒绝再玩.wav","artist":null,"album":null,"uri":"NAS/local/张国荣《风再起时》LPCD45/02.拒绝再玩.wav","trackType":"wav"} Aug 23 12:49:46 volumio-x86 volumio[960]: verbose: CURRENT POSITION 1 Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreStateMachine::syncState stateService pause Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreStateMachine::syncState currentStatus pause Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:49:46 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreStateMachine::stPlaybackTimer Aug 23 12:49:46 volumio-x86 volumio[960]: info: ControllerMpd::pushState Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreCommandRouter::servicePushState Aug 23 12:49:46 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:46 volumio-x86 volumio[960]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":17985,"duration":216,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"02.拒绝再玩.wav","artist":null,"album":null,"uri":"NAS/local/张国荣《风再起时》LPCD45/02.拒绝再玩.wav","trackType":"wav"} Aug 23 12:49:46 volumio-x86 volumio[960]: verbose: CURRENT POSITION 1 Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreStateMachine::syncState stateService pause Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreStateMachine::syncState currentStatus pause Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreStateMachine::pushState Aug 23 12:49:46 volumio-x86 volumio[960]: info: CorePlayQueue::getTrack 1 Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreCommandRouter::volumioPushState Aug 23 12:49:46 volumio-x86 volumio[960]: info: CoreStateMachine::stPlaybackTimer Aug 23 12:49:46 volumio-x86 volumio[960]: info: ------------------------------ 73ms Aug 23 12:49:46 volumio-x86 volumio[960]: info: ------------------------------ 72ms Aug 23 12:49:46 volumio-x86 volumio[960]: info: ------------------------------ 71ms Aug 23 12:49:46 volumio-x86 volumio[960]: info: ------------------------------ 70ms Aug 23 12:49:46 volumio-x86 volumio[960]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 23 12:49:46 volumio-x86 volumio[960]: Error: ENOTDIR: not a directory, scandir '/tmp/peppyrunning' Aug 23 12:49:46 volumio-x86 volumio[960]: at Object.readdirSync (fs.js:1048:3) Aug 23 12:49:46 volumio-x86 volumio[960]: at rmkidsSync (/data/plugins/user_interface/peppy_screensaver/node_modules/rimraf/rimraf.js:349:11) Aug 23 12:49:46 volumio-x86 volumio[960]: at rmdirSync (/data/plugins/user_interface/peppy_screensaver/node_modules/rimraf/rimraf.js:342:7) Aug 23 12:49:46 volumio-x86 volumio[960]: at Function.rimrafSync [as sync] (/data/plugins/user_interface/peppy_screensaver/node_modules/rimraf/rimraf.js:319:62) Aug 23 12:49:46 volumio-x86 volumio[960]: at Object.removeSync (/data/plugins/user_interface/peppy_screensaver/node_modules/fs-extra/lib/remove/index.js:4:17) Aug 23 12:49:46 volumio-x86 volumio[960]: at Socket. (/data/plugins/user_interface/peppy_screensaver/index.js:225:48) Aug 23 12:49:46 volumio-x86 volumio[960]: at Socket.Emitter.emit (/data/plugins/user_interface/peppy_screensaver/node_modules/component-emitter/index.js:145:20) Aug 23 12:49:46 volumio-x86 volumio[960]: at Socket.onevent (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/socket.js:278:10) Aug 23 12:49:46 volumio-x86 volumio[960]: at Socket.onpacket (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/socket.js:236:12) Aug 23 12:49:46 volumio-x86 volumio[960]: at Manager. (/data/plugins/user_interface/peppy_screensaver/node_modules/component-bind/index.js:21:15) Aug 23 12:49:46 volumio-x86 volumio[960]: at Manager.Emitter.emit (/data/plugins/user_interface/peppy_screensaver/node_modules/component-emitter/index.js:145:20) Aug 23 12:49:46 volumio-x86 volumio[960]: at Manager.ondecoded (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/manager.js:349:8) Aug 23 12:49:46 volumio-x86 volumio[960]: at Decoder. (/data/plugins/user_interface/peppy_screensaver/node_modules/component-bind/index.js:21:15) Aug 23 12:49:46 volumio-x86 volumio[960]: at Decoder.Emitter.emit (/data/plugins/user_interface/peppy_screensaver/node_modules/component-emitter/index.js:145:20) Aug 23 12:49:46 volumio-x86 volumio[960]: at Decoder.add (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-parser/index.js:251:12) Aug 23 12:49:46 volumio-x86 volumio[960]: at Manager.ondata (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/manager.js:339:16) { Aug 23 12:49:46 volumio-x86 volumio[960]: errno: -20, Aug 23 12:49:46 volumio-x86 volumio[960]: syscall: 'scandir', Aug 23 12:49:46 volumio-x86 volumio[960]: code: 'ENOTDIR', Aug 23 12:49:46 volumio-x86 volumio[960]: path: '/tmp/peppyrunning' Aug 23 12:49:46 volumio-x86 volumio[960]: } Aug 23 12:49:46 volumio-x86 volumio[960]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 23 12:49:46 volumio-x86 sudo[2306]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-08-23 12:48 Aug 23 12:49:46 volumio-x86 sudo[2306]: 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"