-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Mon 2024-04-15 18:47:50 CEST. -- Apr 15 18:46:00 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: wizard , getDonation Apr 15 18:46:00 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: my_volumio , detectVolumioHardware Apr 15 18:46:00 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: wizard , getDonationsArray Apr 15 18:46:00 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: wizard , getDoneMessage Apr 15 18:46:00 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: my_volumio , detectVolumioHardware Apr 15 18:46:00 volumio wireless.js[2159]: trying... Apr 15 18:46:00 volumio sudo[2386]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 15 18:46:00 volumio sudo[2386]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 18:46:00 volumio sudo[2386]: pam_unix(sudo:session): session closed for user root Apr 15 18:46:01 volumio wireless.js[2159]: Overtime, starting plan B Apr 15 18:46:01 volumio wireless.js[2159]: STARTING HOTSPOT Apr 15 18:46:01 volumio wpa_supplicant[2224]: nl80211: Failed to open /proc/sys/net/ipv4/conf/p2p-dev-wlan0/drop_unicast_in_l2_multicast: No such file or directory Apr 15 18:46:01 volumio wpa_supplicant[2224]: nl80211: Failed to set IPv4 unicast in multicast filter Apr 15 18:46:01 volumio wpa_supplicant[2224]: nl80211: Failed to open /proc/sys/net/ipv4/conf/p2p-dev-wlan0/drop_unicast_in_l2_multicast: No such file or directory Apr 15 18:46:01 volumio wpa_supplicant[2224]: nl80211: Failed to set IPv4 unicast in multicast filter Apr 15 18:46:01 volumio wpa_supplicant[2224]: nl80211: deinit ifname=p2p-dev-wlan0 disabled_11b_rates=0 Apr 15 18:46:01 volumio wpa_supplicant[2224]: p2p-dev-wlan0: CTRL-EVENT-TERMINATING Apr 15 18:46:01 volumio wpa_supplicant[2224]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Apr 15 18:46:02 volumio wpa_supplicant[2224]: wlan0: CTRL-EVENT-TERMINATING Apr 15 18:46:04 volumio sudo[2395]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Apr 15 18:46:04 volumio sudo[2395]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 18:46:04 volumio sudo[2395]: pam_unix(sudo:session): session closed for user root Apr 15 18:46:04 volumio sudo[2398]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Apr 15 18:46:04 volumio sudo[2398]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 18:46:04 volumio sudo[2398]: pam_unix(sudo:session): session closed for user root Apr 15 18:46:04 volumio avahi-daemon[542]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. Apr 15 18:46:04 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Apr 15 18:46:04 volumio avahi-daemon[542]: New relevant interface wlan0.IPv4 for mDNS. Apr 15 18:46:04 volumio avahi-daemon[542]: Registering new address record for 192.168.211.1 on wlan0.IPv4. Apr 15 18:46:04 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Apr 15 18:46:04 volumio hostapd[2428]: Configuration file: /etc/hostapd/hostapd.conf Apr 15 18:46:04 volumio hostapd[2428]: wlan0: Could not connect to kernel driver Apr 15 18:46:04 volumio hostapd[2428]: Using interface wlan0 with hwaddr b8:27:eb:17:df:1a and ssid "Volumio-7F0B7" Apr 15 18:46:04 volumio hostapd[2428]: wlan0: interface state UNINITIALIZED->ENABLED Apr 15 18:46:04 volumio hostapd[2428]: wlan0: AP-ENABLED Apr 15 18:46:04 volumio dhcpcd[2268]: wlan0: carrier acquired Apr 15 18:46:04 volumio systemd[1]: Started Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Apr 15 18:46:04 volumio dhcpcd[2268]: wlan0: IAID eb:17:df:1a Apr 15 18:46:04 volumio dhcpcd[2268]: wlan0: adding address fe80::43ea:6a88:74c2:571d Apr 15 18:46:04 volumio dhcpcd[2268]: ipv6_addaddr1: Permission denied Apr 15 18:46:04 volumio dhcpcd[2268]: wlan0: soliciting a DHCP lease Apr 15 18:46:04 volumio iwconfig[2449]: Error for wireless request "Set Power Management" (8B2C) : Apr 15 18:46:04 volumio iwconfig[2449]: SET failed on device wlan0 ; Invalid argument. Apr 15 18:46:04 volumio systemd[1]: Started Wireless Services. Apr 15 18:46:04 volumio sudo[2157]: pam_unix(sudo:session): session closed for user root Apr 15 18:46:05 volumio dhcpcd[2268]: wlan0: soliciting an IPv6 router Apr 15 18:46:05 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: wizard , setWizardAction Apr 15 18:46:05 volumio volumio[1585]: info: CoreCommandRouter::Reload Ui Apr 15 18:46:05 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: system , setShowWizard Apr 15 18:46:05 volumio volumio[1585]: info: Wizard terminated Successfully Apr 15 18:46:05 volumio volumio[1585]: info: CoreCommandRouter::volumiosetStartupVolume Apr 15 18:46:05 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 15 18:46:05 volumio volumio[1585]: info: Player Reboot required after I2S DAC has been enabled in wizard Apr 15 18:46:05 volumio volumio[1585]: info: Discovery: this is already registered, bc1973b5-4cf4-499f-a88a-330017567df3 Apr 15 18:46:05 volumio volumio[1585]: info: Discovery: Found device Volumio Apr 15 18:46:05 volumio volumio[1585]: info: CoreCommandRouter::volumioGetState Apr 15 18:46:05 volumio volumio[1585]: info: CorePlayQueue::getTrack 0 Apr 15 18:46:06 volumio ntpd[686]: Listen normally on 5 wlan0 192.168.211.1:123 Apr 15 18:46:06 volumio ntpd[686]: new interface(s) found: waking up resolver Apr 15 18:46:09 volumio sudo[2453]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 15 18:46:09 volumio sudo[2453]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 18:46:09 volumio sudo[2453]: pam_unix(sudo:session): session closed for user root Apr 15 18:46:09 volumio sudo[2455]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 15 18:46:09 volumio sudo[2455]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 18:46:09 volumio sudo[2455]: pam_unix(sudo:session): session closed for user root Apr 15 18:46:09 volumio volumio[1585]: verbose: New Socket.io Connection to 192.168.0.21 from 192.168.0.12 UA: okhttp/3.12.12 Total Clients: 6 Apr 15 18:46:09 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 15 18:46:09 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 15 18:46:09 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 15 18:46:09 volumio volumio[1585]: info: CoreCommandRouter::volumioGetVisibleSources Apr 15 18:46:09 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 18:46:09 volumio volumio[1585]: info: CoreCommandRouter::volumioGetState Apr 15 18:46:09 volumio volumio[1585]: info: CorePlayQueue::getTrack 0 Apr 15 18:46:09 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 15 18:46:09 volumio dhcpcd[2268]: wlan0: probing for an IPv4LL address Apr 15 18:46:09 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: wizard , reportWirelessConnection Apr 15 18:46:09 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessInfo Apr 15 18:46:09 volumio sudo[2459]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 15 18:46:09 volumio sudo[2459]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 18:46:09 volumio sudo[2459]: pam_unix(sudo:session): session closed for user root Apr 15 18:46:10 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 15 18:46:10 volumio volumio[1585]: info: Received Get System Info Apr 15 18:46:10 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 15 18:46:10 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 15 18:46:10 volumio volumio[1585]: info: Discovery: Getting this device information Apr 15 18:46:10 volumio volumio[1585]: info: CoreCommandRouter::volumioGetState Apr 15 18:46:10 volumio volumio[1585]: info: CorePlayQueue::getTrack 0 Apr 15 18:46:10 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 15 18:46:10 volumio volumio[1585]: info: CoreCommandRouter::volumioGetState Apr 15 18:46:10 volumio volumio[1585]: info: CorePlayQueue::getTrack 0 Apr 15 18:46:10 volumio volumio[1585]: info: Listing playlists Apr 15 18:46:10 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 15 18:46:10 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 15 18:46:11 volumio sudo[2462]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 15 18:46:11 volumio sudo[2462]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 18:46:11 volumio sudo[2462]: pam_unix(sudo:session): session closed for user root Apr 15 18:46:11 volumio sudo[2464]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 15 18:46:11 volumio sudo[2464]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 18:46:11 volumio sudo[2464]: pam_unix(sudo:session): session closed for user root Apr 15 18:46:11 volumio volumio[1585]: verbose: New Socket.io Connection to 192.168.0.21 from 192.168.0.12 UA: okhttp/3.12.12 Total Clients: 6 Apr 15 18:46:11 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 15 18:46:11 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 15 18:46:11 volumio volumio[1585]: info: CoreCommandRouter::volumioGetVisibleSources Apr 15 18:46:11 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 15 18:46:11 volumio volumio[1585]: info: CoreCommandRouter::volumioGetState Apr 15 18:46:11 volumio volumio[1585]: info: CorePlayQueue::getTrack 0 Apr 15 18:46:11 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 15 18:46:11 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 15 18:46:11 volumio volumio[1585]: info: Received Get System Info Apr 15 18:46:11 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 15 18:46:11 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 15 18:46:11 volumio volumio[1585]: info: Discovery: Getting this device information Apr 15 18:46:11 volumio volumio[1585]: info: CoreCommandRouter::volumioGetState Apr 15 18:46:11 volumio volumio[1585]: info: CorePlayQueue::getTrack 0 Apr 15 18:46:11 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 15 18:46:11 volumio volumio[1585]: info: CoreCommandRouter::volumioGetState Apr 15 18:46:11 volumio volumio[1585]: info: CorePlayQueue::getTrack 0 Apr 15 18:46:12 volumio volumio[1585]: info: Listing playlists Apr 15 18:46:12 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 15 18:46:12 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 15 18:46:12 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 15 18:46:12 volumio volumio[1585]: info: CoreCommandRouter::volumioGetState Apr 15 18:46:12 volumio volumio[1585]: info: CorePlayQueue::getTrack 0 Apr 15 18:46:13 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 15 18:46:13 volumio volumio[1585]: info: Received Get System Info Apr 15 18:46:13 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 15 18:46:13 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 15 18:46:13 volumio volumio[1585]: info: Discovery: Getting this device information Apr 15 18:46:13 volumio volumio[1585]: info: CoreCommandRouter::volumioGetState Apr 15 18:46:13 volumio volumio[1585]: info: CorePlayQueue::getTrack 0 Apr 15 18:46:13 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 15 18:46:14 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: upnp , onRestart Apr 15 18:46:14 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: network , onNetworkingRestart Apr 15 18:46:14 volumio volumio[1585]: info: Refreshing Cached IP Addresses Apr 15 18:46:14 volumio sudo[2468]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall upmpdcli Apr 15 18:46:14 volumio sudo[2468]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 18:46:14 volumio sudo[2468]: pam_unix(sudo:session): session closed for user root Apr 15 18:46:14 volumio sudo[2470]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 15 18:46:14 volumio sudo[2470]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 18:46:14 volumio sudo[2470]: pam_unix(sudo:session): session closed for user root Apr 15 18:46:14 volumio volumio[1585]: error: Upnp client error: Error: This socket has been ended by the other party Apr 15 18:46:14 volumio sudo[2473]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 15 18:46:14 volumio sudo[2473]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 18:46:14 volumio sudo[2473]: pam_unix(sudo:session): session closed for user root Apr 15 18:46:15 volumio dhcpcd[2268]: wlan0: using IPv4LL address 169.254.139.165 Apr 15 18:46:15 volumio avahi-daemon[542]: Registering new address record for 169.254.139.165 on wlan0.IPv4. Apr 15 18:46:15 volumio dhcpcd[2268]: wlan0: adding route to 169.254.0.0/16 Apr 15 18:46:16 volumio ntpd[686]: Listen normally on 6 wlan0 169.254.139.165:123 Apr 15 18:46:16 volumio ntpd[686]: new interface(s) found: waking up resolver Apr 15 18:46:18 volumio volumio[1585]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 18:46:18 volumio volumio[1585]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 18:46:18 volumio volumio[1585]: info: Retrieving Cloud Streaming UI Apr 15 18:46:18 volumio volumio[1585]: info: Getting Tidal Cloud Configuration Apr 15 18:46:18 volumio volumio[1585]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 18:46:18 volumio volumio[1585]: info: Getting Qobuz Cloud Configuration Apr 15 18:46:18 volumio volumio[1585]: info: Asking plugin for UI Config Apr 15 18:46:18 volumio volumio[1585]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 18:46:18 volumio volumio[1585]: info: Getting Spotify Cloud Configuration Apr 15 18:46:18 volumio volumio[1585]: info: Asking plugin for UI Config Apr 15 18:46:18 volumio volumio[1585]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 18:46:18 volumio volumio[1585]: info: Saving Spotify Acccount Apr 15 18:46:18 volumio volumio[1585]: info: Got Tidal Cloud Configuration Apr 15 18:46:18 volumio volumio[1585]: info: Got it Apr 15 18:46:18 volumio volumio[1585]: info: Got it Apr 15 18:46:18 volumio volumio[1585]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Apr 15 18:46:18 volumio volumio[1585]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 15 18:46:18 volumio volumio[1585]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Apr 15 18:46:18 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 15 18:46:18 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 15 18:46:18 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 15 18:46:18 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 15 18:46:18 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 15 18:46:18 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 15 18:46:18 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 15 18:46:18 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 15 18:46:18 volumio volumio[1585]: info: CoreCommandRouter::volumioGetBrowseSources Apr 15 18:46:18 volumio volumio[1585]: info: CoreCommandRouter::volumioGetBrowseSources Apr 15 18:46:18 volumio volumio[1585]: info: CoreCommandRouter::volumioGetBrowseSources Apr 15 18:46:19 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 15 18:46:19 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Apr 15 18:46:23 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 15 18:46:24 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: mpd , rescanDb Apr 15 18:46:24 volumio volumio[1585]: verbose: ControllerMpd::sendMpdCommand rescan Apr 15 18:46:24 volumio volumio[1585]: verbose: ControllerMpd::sendMpdCommand status Apr 15 18:46:24 volumio volumio[1585]: info: Apr 15 18:46:24 volumio volumio[1585]: ---------------------------- MPD announces state update: update Apr 15 18:46:24 volumio volumio[1585]: info: sendMpdCommand rescan took 10 milliseconds Apr 15 18:46:24 volumio volumio[1585]: info: ControllerMpd::getState Apr 15 18:46:24 volumio volumio[1585]: verbose: ControllerMpd::sendMpdCommand status Apr 15 18:46:24 volumio volumio[1585]: info: sendMpdCommand status took 18 milliseconds Apr 15 18:46:24 volumio volumio[1585]: info: sendMpdCommand status took 14 milliseconds Apr 15 18:46:24 volumio volumio[1585]: verbose: ControllerMpd::parseState Apr 15 18:46:24 volumio volumio[1585]: info: Command Router : Notfying DB Updatetrue Apr 15 18:46:24 volumio volumio[1585]: verbose: ControllerMpd::parseState Apr 15 18:46:24 volumio volumio[1585]: info: ControllerMpd::pushState Apr 15 18:46:24 volumio volumio[1585]: info: CoreCommandRouter::servicePushState Apr 15 18:46:24 volumio volumio[1585]: info: CoreStateMachine::pushState Apr 15 18:46:24 volumio volumio[1585]: info: CorePlayQueue::getTrack 0 Apr 15 18:46:24 volumio volumio[1585]: info: CoreCommandRouter::volumioPushState Apr 15 18:46:24 volumio volumio[1585]: info: CorePlayQueue::getTrack 0 Apr 15 18:46:24 volumio volumio[1585]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 15 18:46:24 volumio volumio[1585]: verbose: CURRENT POSITION 0 Apr 15 18:46:24 volumio volumio[1585]: info: CoreStateMachine::syncState stateService stop Apr 15 18:46:24 volumio volumio[1585]: info: CoreStateMachine::syncState currentStatus stop Apr 15 18:46:24 volumio volumio[1585]: info: CoreStateMachine::pushState Apr 15 18:46:24 volumio volumio[1585]: info: CorePlayQueue::getTrack 0 Apr 15 18:46:24 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 18:46:24 volumio volumio[1585]: info: CoreCommandRouter::volumioPushState Apr 15 18:46:24 volumio volumio[1585]: info: No code Apr 15 18:46:24 volumio volumio[1585]: info: CoreStateMachine::pushState Apr 15 18:46:24 volumio volumio[1585]: info: CorePlayQueue::getTrack 0 Apr 15 18:46:24 volumio volumio[1585]: info: CoreCommandRouter::volumioPushState Apr 15 18:46:24 volumio volumio[1585]: info: ------------------------------ 129ms Apr 15 18:46:24 volumio sudo[2501]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 15 18:46:24 volumio sudo[2501]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 18:46:25 volumio sudo[2501]: pam_unix(sudo:session): session closed for user root Apr 15 18:46:25 volumio sudo[2503]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 15 18:46:25 volumio sudo[2503]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 18:46:25 volumio sudo[2503]: pam_unix(sudo:session): session closed for user root Apr 15 18:46:25 volumio sudo[2507]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 15 18:46:25 volumio sudo[2507]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 18:46:25 volumio sudo[2507]: pam_unix(sudo:session): session closed for user root Apr 15 18:46:25 volumio volumio[1585]: info: Upmpdcli Daemon Started Apr 15 18:46:27 volumio volumio[1585]: info: CoreCommandRouter::Close All Modals sent Apr 15 18:46:27 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 15 18:46:29 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 15 18:46:29 volumio volumio[1585]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Apr 15 18:46:29 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Apr 15 18:46:29 volumio volumio[1585]: info: Received Get System Version Apr 15 18:46:29 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 15 18:46:29 volumio volumio[1585]: info: Received Get System Info Apr 15 18:46:29 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 15 18:46:29 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 15 18:46:29 volumio volumio[1585]: info: Discovery: Getting this device information Apr 15 18:46:29 volumio volumio[1585]: info: CoreCommandRouter::volumioGetState Apr 15 18:46:29 volumio volumio[1585]: info: CorePlayQueue::getTrack 0 Apr 15 18:46:29 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 15 18:46:31 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 15 18:46:35 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 15 18:46:39 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 15 18:46:43 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 15 18:46:47 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 15 18:46:51 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 15 18:46:55 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 15 18:46:59 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 15 18:47:03 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 15 18:47:07 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 15 18:47:11 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 15 18:47:15 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 15 18:47:18 volumio volumio[1585]: info: MPD Database updated - AlbumList cache refreshed Apr 15 18:47:18 volumio volumio[1585]: info: Apr 15 18:47:18 volumio volumio[1585]: ---------------------------- MPD announces state update: database Apr 15 18:47:18 volumio volumio[1585]: verbose: ControllerMpd::sendMpdCommand status Apr 15 18:47:18 volumio volumio[1585]: info: Apr 15 18:47:18 volumio volumio[1585]: ---------------------------- MPD announces state update: update Apr 15 18:47:18 volumio volumio[1585]: info: ControllerMpd::getState Apr 15 18:47:18 volumio volumio[1585]: verbose: ControllerMpd::sendMpdCommand status Apr 15 18:47:18 volumio volumio[1585]: info: ControllerMpd::getState Apr 15 18:47:18 volumio volumio[1585]: verbose: ControllerMpd::sendMpdCommand status Apr 15 18:47:18 volumio volumio[1585]: info: sendMpdCommand status took 495 milliseconds Apr 15 18:47:18 volumio volumio[1585]: info: sendMpdCommand status took 493 milliseconds Apr 15 18:47:18 volumio volumio[1585]: info: sendMpdCommand status took 493 milliseconds Apr 15 18:47:18 volumio volumio[1585]: verbose: ControllerMpd::parseState Apr 15 18:47:18 volumio volumio[1585]: info: Command Router : Notfying DB Updatefalse Apr 15 18:47:18 volumio volumio[1585]: info: CoreCommandRouter::Close All Modals sent Apr 15 18:47:18 volumio volumio[1585]: verbose: ControllerMpd::parseState Apr 15 18:47:18 volumio volumio[1585]: verbose: ControllerMpd::parseState Apr 15 18:47:18 volumio volumio[1585]: info: ControllerMpd::pushState Apr 15 18:47:18 volumio volumio[1585]: info: CoreCommandRouter::servicePushState Apr 15 18:47:18 volumio volumio[1585]: info: CoreStateMachine::pushState Apr 15 18:47:18 volumio volumio[1585]: info: CorePlayQueue::getTrack 0 Apr 15 18:47:18 volumio volumio[1585]: info: CoreCommandRouter::volumioPushState Apr 15 18:47:18 volumio volumio[1585]: info: CorePlayQueue::getTrack 0 Apr 15 18:47:18 volumio volumio[1585]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 15 18:47:18 volumio volumio[1585]: verbose: CURRENT POSITION 0 Apr 15 18:47:18 volumio volumio[1585]: info: CoreStateMachine::syncState stateService stop Apr 15 18:47:18 volumio volumio[1585]: info: CoreStateMachine::syncState currentStatus stop Apr 15 18:47:18 volumio volumio[1585]: info: CoreStateMachine::pushState Apr 15 18:47:18 volumio volumio[1585]: info: CorePlayQueue::getTrack 0 Apr 15 18:47:18 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 15 18:47:18 volumio volumio[1585]: info: CoreCommandRouter::volumioPushState Apr 15 18:47:18 volumio volumio[1585]: info: No code Apr 15 18:47:18 volumio volumio[1585]: info: CoreStateMachine::pushState Apr 15 18:47:18 volumio volumio[1585]: info: CorePlayQueue::getTrack 0 Apr 15 18:47:18 volumio volumio[1585]: info: CoreCommandRouter::volumioPushState Apr 15 18:47:18 volumio volumio[1585]: info: ControllerMpd::pushState Apr 15 18:47:18 volumio volumio[1585]: info: CoreCommandRouter::servicePushState Apr 15 18:47:18 volumio volumio[1585]: info: CoreStateMachine::pushState Apr 15 18:47:18 volumio volumio[1585]: info: CorePlayQueue::getTrack 0 Apr 15 18:47:18 volumio volumio[1585]: info: CoreCommandRouter::volumioPushState Apr 15 18:47:18 volumio volumio[1585]: info: CorePlayQueue::getTrack 0 Apr 15 18:47:18 volumio volumio[1585]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 15 18:47:18 volumio volumio[1585]: verbose: CURRENT POSITION 0 Apr 15 18:47:18 volumio volumio[1585]: info: CoreStateMachine::syncState stateService stop Apr 15 18:47:18 volumio volumio[1585]: info: CoreStateMachine::syncState currentStatus stop Apr 15 18:47:18 volumio volumio[1585]: info: CoreStateMachine::pushState Apr 15 18:47:18 volumio volumio[1585]: info: CorePlayQueue::getTrack 0 Apr 15 18:47:18 volumio volumio[1585]: info: CoreCommandRouter::volumioPushState Apr 15 18:47:18 volumio volumio[1585]: info: No code Apr 15 18:47:18 volumio volumio[1585]: info: CoreStateMachine::pushState Apr 15 18:47:18 volumio volumio[1585]: info: CorePlayQueue::getTrack 0 Apr 15 18:47:18 volumio volumio[1585]: info: CoreCommandRouter::volumioPushState Apr 15 18:47:18 volumio volumio[1585]: info: ------------------------------ 663ms Apr 15 18:47:18 volumio volumio[1585]: info: ------------------------------ 665ms Apr 15 18:47:19 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 15 18:47:23 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 15 18:47:27 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 15 18:47:31 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 15 18:47:35 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 15 18:47:39 volumio volumio[1585]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 15 18:47:41 volumio volumio[1585]: info: CoreCommandRouter::volumioGetState Apr 15 18:47:41 volumio volumio[1585]: info: CorePlayQueue::getTrack 0 Apr 15 18:47:42 volumio volumio[1585]: info: CoreCommandRouter::volumioGetQueue Apr 15 18:47:42 volumio volumio[1585]: info: CoreStateMachine::getQueue Apr 15 18:47:42 volumio volumio[1585]: info: CorePlayQueue::getQueue Apr 15 18:47:49 volumio volumio[1585]: info: Preload queue cleared Apr 15 18:47:49 volumio volumio[1585]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 15 18:47:49 volumio volumio[1585]: info: CoreStateMachine::ClearQueue Apr 15 18:47:49 volumio volumio[1585]: info: CoreStateMachine::stop Apr 15 18:47:49 volumio volumio[1585]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 15 18:47:49 volumio volumio[1585]: info: CorePlayQueue::clearPlayQueue Apr 15 18:47:49 volumio volumio[1585]: info: CorePlayQueue::saveQueue Apr 15 18:47:49 volumio volumio[1585]: info: CoreCommandRouter::volumioPushQueue Apr 15 18:47:49 volumio volumio[1585]: info: CoreStateMachine::addQueueItems Apr 15 18:47:49 volumio volumio[1585]: info: CorePlayQueue::addQueueItems Apr 15 18:47:49 volumio volumio[1585]: info: Preload queue cleared Apr 15 18:47:49 volumio volumio[1585]: info: Adding Item to queue: music-library/USB/Audio/1980 - Jon & Vangelis - Short Stories (Polydor, 2383 565, DE, 24-192) Apr 15 18:47:49 volumio volumio[1585]: info: Exploding uri music-library/USB/Audio/1980 - Jon & Vangelis - Short Stories (Polydor, 2383 565, DE, 24-192) in service mpd Apr 15 18:47:49 volumio volumio[1585]: info: ALBUMART /albumart?cacheid=858&web=Jon%20%26%20Vangelis/Short%20Stories/extralarge&path=%2Fmnt%2FUSB%2FAudio%2F1980%20-%20Jon%20%26%20Vangelis%20-%20Short%20Stories%20(Polydor%2C%202383%20565%2C%20DE%2C%2024-192)%2F1980%20-%20Jon%20%26%20Vangelis%20-%20Short%20Stories.cue&metadata=false Apr 15 18:47:49 volumio volumio[1585]: info: URI /mnt/USB/Audio/1980 - Jon & Vangelis - Short Stories (Polydor, 2383 565, DE, 24-192)/1980 - Jon & Vangelis - Short Stories.cue Apr 15 18:47:49 volumio volumio[1585]: info: ALBUMART /albumart?cacheid=858&web=Jon%20%26%20Vangelis/Short%20Stories/extralarge&path=%2Fmnt%2FUSB%2FAudio%2F1980%20-%20Jon%20%26%20Vangelis%20-%20Short%20Stories%20(Polydor%2C%202383%20565%2C%20DE%2C%2024-192)%2F1980%20-%20Jon%20%26%20Vangelis%20-%20Short%20Stories.cue&metadata=false Apr 15 18:47:49 volumio volumio[1585]: info: URI /mnt/USB/Audio/1980 - Jon & Vangelis - Short Stories (Polydor, 2383 565, DE, 24-192)/1980 - Jon & Vangelis - Short Stories.cue Apr 15 18:47:49 volumio volumio[1585]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 15 18:47:49 volumio volumio[1585]: Error: Unable to resolve or reject the same promise twice Apr 15 18:47:49 volumio volumio[1585]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Apr 15 18:47:49 volumio volumio[1585]: at /volumio/app/plugins/music_service/mpd/index.js:2568:21 Apr 15 18:47:49 volumio volumio[1585]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) Apr 15 18:47:49 volumio volumio[1585]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) Apr 15 18:47:49 volumio volumio[1585]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) Apr 15 18:47:49 volumio volumio[1585]: at Socket.emit (events.js:315:20) Apr 15 18:47:49 volumio volumio[1585]: at addChunk (internal/streams/readable.js:309:12) Apr 15 18:47:49 volumio volumio[1585]: at readableAddChunk (internal/streams/readable.js:280:11) Apr 15 18:47:49 volumio volumio[1585]: at Socket.Readable.push (internal/streams/readable.js:223:10) Apr 15 18:47:49 volumio volumio[1585]: at Pipe.onStreamRead (internal/stream_base_commons.js:188:23) Apr 15 18:47:49 volumio volumio[1585]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 15 18:47:50 volumio sudo[2567]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-15 18:46 Apr 15 18:47:50 volumio sudo[2567]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 21 Feb 2024 09:37:22 PM CET" VOLUMIO_VERSION="3.631" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fdd9dd1169c06c1ad0a30ddd24c91b6b"