-- Logs begin at Sat 2024-07-20 20:50:19 CST, end at Sun 2024-07-21 15:36:56 CST. -- Jul 21 15:35:02 volumio volumio[1157]: info: CoreCommandRouter::volumioGetState Jul 21 15:35:02 volumio volumio[1157]: info: CorePlayQueue::getTrack 1 Jul 21 15:35:05 volumio volumio[1157]: info: CoreCommandRouter::volumioGetState Jul 21 15:35:05 volumio volumio[1157]: info: CorePlayQueue::getTrack 1 Jul 21 15:35:08 volumio volumio[1157]: info: CoreCommandRouter::volumioGetState Jul 21 15:35:08 volumio volumio[1157]: info: CorePlayQueue::getTrack 1 Jul 21 15:35:11 volumio volumio[1157]: info: CoreCommandRouter::volumioGetState Jul 21 15:35:11 volumio volumio[1157]: info: CorePlayQueue::getTrack 1 Jul 21 15:35:14 volumio volumio[1157]: info: CoreCommandRouter::volumioGetState Jul 21 15:35:14 volumio volumio[1157]: info: CorePlayQueue::getTrack 1 Jul 21 15:35:17 volumio volumio[1157]: info: CoreCommandRouter::volumioGetState Jul 21 15:35:17 volumio volumio[1157]: info: CorePlayQueue::getTrack 1 Jul 21 15:35:21 volumio volumio[1157]: info: CoreCommandRouter::volumioGetState Jul 21 15:35:21 volumio volumio[1157]: info: CorePlayQueue::getTrack 1 Jul 21 15:35:24 volumio volumio[1157]: info: CoreCommandRouter::volumioGetState Jul 21 15:35:24 volumio volumio[1157]: info: CorePlayQueue::getTrack 1 Jul 21 15:35:24 volumio volumio[1157]: verbose: ControllerMpd::sendMpdCommand add "https://music.wkczy.com:1443/rest/stream.view?id=06ba66dc70535656eafa0181c50a0445&format=raw&u=wk224&t=1fe253d10e596efd339e50c46dbb84b4&s=l92vM&v=1.10.2&f=json&c=volusonic" Jul 21 15:35:24 volumio volumio[1157]: info: sendMpdCommand stop took 31311 milliseconds Jul 21 15:35:24 volumio volumio[1157]: verbose: ControllerMpd::sendMpdCommand clear Jul 21 15:35:24 volumio volumio[1157]: info: Jul 21 15:35:24 volumio volumio[1157]: ---------------------------- MPD announces system playlist update Jul 21 15:35:24 volumio volumio[1157]: info: Ignoring MPD Status Update Jul 21 15:35:24 volumio volumio[1157]: info: Jul 21 15:35:24 volumio volumio[1157]: ---------------------------- MPD announces system playlist update Jul 21 15:35:24 volumio volumio[1157]: info: Ignoring MPD Status Update Jul 21 15:35:24 volumio volumio[1157]: info: sendMpdCommand add "https://music.wkczy.com:1443/rest/stream.view?id=06ba66dc70535656eafa0181c50a0445&format=raw&u=wk224&t=1fe253d10e596efd339e50c46dbb84b4&s=l92vM&v=1.10.2&f=json&c=volusonic" took 6 milliseconds Jul 21 15:35:24 volumio volumio[1157]: info: sendMpdCommand clear took 5 milliseconds Jul 21 15:35:24 volumio volumio[1157]: verbose: ControllerMpd::sendMpdCommand play Jul 21 15:35:24 volumio volumio[1157]: verbose: ControllerMpd::sendMpdCommand load "https://music.wkczy.com:1443/rest/stream.view?id=be42794b41606a2e41d95db4f96b49c1&format=raw&u=wk224&t=1fe253d10e596efd339e50c46dbb84b4&s=l92vM&v=1.10.2&f=json&c=volusonic" Jul 21 15:35:24 volumio volumio[1157]: error: updateQueue error: null Jul 21 15:35:24 volumio volumio[1157]: error: updateQueue error: null Jul 21 15:35:24 volumio volumio[1157]: info: ------------------------------ 10ms Jul 21 15:35:24 volumio volumio[1157]: info: ------------------------------ 9ms Jul 21 15:35:24 volumio volumio[1157]: info: sendMpdCommand play took 6 milliseconds Jul 21 15:35:24 volumio volumio[1157]: info: ControllerMpd::getState Jul 21 15:35:24 volumio volumio[1157]: verbose: ControllerMpd::sendMpdCommand status Jul 21 15:35:25 volumio dhcpcd[825]: wlan0: carrier lost Jul 21 15:35:25 volumio kernel: wlan0: deauthenticated from 80:ea:07:fb:1d:24 (Reason: 34=DISASSOC_LOW_ACK) Jul 21 15:35:25 volumio avahi-daemon[730]: Withdrawing address record for 192.168.99.209 on wlan0. Jul 21 15:35:25 volumio avahi-daemon[730]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.99.209. Jul 21 15:35:25 volumio wpa_supplicant[1067]: wlan0: CTRL-EVENT-DISCONNECTED bssid=80:ea:07:fb:1d:24 reason=34 Jul 21 15:35:25 volumio avahi-daemon[730]: Interface wlan0.IPv4 no longer relevant for mDNS. Jul 21 15:35:26 volumio volumio[1157]: info: Discovery: A device disappeared from network Jul 21 15:35:26 volumio volumio[1157]: info: Discovery: Device volumio disappeared from network Jul 21 15:35:26 volumio dhcpcd[825]: wlan0: deleting route to 192.168.99.0/24 Jul 21 15:35:26 volumio dhcpcd[825]: wlan0: deleting default route via 192.168.99.1 Jul 21 15:35:27 volumio volumio[1157]: info: CoreCommandRouter::volumioGetState Jul 21 15:35:27 volumio volumio[1157]: info: CorePlayQueue::getTrack 1 Jul 21 15:35:27 volumio ntpd[910]: Deleting interface #4 wlan0, 192.168.99.209#123, interface stats: received=417, sent=438, dropped=0, active_time=62664 secs Jul 21 15:35:27 volumio ntpd[910]: 74.50.98.131 local addr 192.168.99.209 -> Jul 21 15:35:27 volumio ntpd[910]: 23.150.41.123 local addr 192.168.99.209 -> Jul 21 15:35:27 volumio ntpd[910]: 216.229.4.66 local addr 192.168.99.209 -> Jul 21 15:35:27 volumio ntpd[910]: 129.250.35.250 local addr 192.168.99.209 -> Jul 21 15:35:27 volumio ntpd[910]: 192.48.105.15 local addr 192.168.99.209 -> Jul 21 15:35:27 volumio ntpd[910]: 23.150.41.122 local addr 192.168.99.209 -> Jul 21 15:35:27 volumio wpa_supplicant[1067]: wlan0: SME: Trying to authenticate with 64:6e:97:2d:c4:c0 (SSID='monat-f-5g' freq=5180 MHz) Jul 21 15:35:27 volumio kernel: wlan0: authenticate with 64:6e:97:2d:c4:c0 Jul 21 15:35:27 volumio kernel: wlan0: send auth to 64:6e:97:2d:c4:c0 (try 1/3) Jul 21 15:35:27 volumio wpa_supplicant[1067]: wlan0: Trying to associate with 64:6e:97:2d:c4:c0 (SSID='monat-f-5g' freq=5180 MHz) Jul 21 15:35:27 volumio kernel: wlan0: authenticated Jul 21 15:35:27 volumio kernel: wlan0: associate with 64:6e:97:2d:c4:c0 (try 1/3) Jul 21 15:35:27 volumio kernel: wlan0: RX AssocResp from 64:6e:97:2d:c4:c0 (capab=0x1011 status=0 aid=4) Jul 21 15:35:27 volumio wpa_supplicant[1067]: wlan0: Associated with 64:6e:97:2d:c4:c0 Jul 21 15:35:27 volumio kernel: wlan0: associated Jul 21 15:35:27 volumio wpa_supplicant[1067]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jul 21 15:35:27 volumio wpa_supplicant[1067]: wlan0: WPA: Key negotiation completed with 64:6e:97:2d:c4:c0 [PTK=CCMP GTK=CCMP] Jul 21 15:35:27 volumio wpa_supplicant[1067]: wlan0: CTRL-EVENT-CONNECTED - Connection to 64:6e:97:2d:c4:c0 completed [id=0 id_str=] Jul 21 15:35:27 volumio dhcpcd[825]: wlan0: carrier acquired Jul 21 15:35:27 volumio kernel: wlan0: Limiting TX power to 20 (20 - 0) dBm as advertised by 64:6e:97:2d:c4:c0 Jul 21 15:35:27 volumio dhcpcd[825]: wlan0: IAID c2:e5:60:1e Jul 21 15:35:27 volumio dhcpcd[825]: wlan0: probing address 192.168.99.209/24 Jul 21 15:35:28 volumio dhcpcd[825]: wlan0: soliciting an IPv6 router Jul 21 15:35:30 volumio volumio[1157]: verbose: ControllerMpd::sendMpdCommand add "https://music.wkczy.com:1443/rest/stream.view?id=be42794b41606a2e41d95db4f96b49c1&format=raw&u=wk224&t=1fe253d10e596efd339e50c46dbb84b4&s=l92vM&v=1.10.2&f=json&c=volusonic" Jul 21 15:35:30 volumio volumio[1157]: info: Jul 21 15:35:30 volumio volumio[1157]: ---------------------------- MPD announces system playlist update Jul 21 15:35:30 volumio volumio[1157]: info: Ignoring MPD Status Update Jul 21 15:35:30 volumio volumio[1157]: info: sendMpdCommand status took 5702 milliseconds Jul 21 15:35:30 volumio volumio[1157]: info: sendMpdCommand add "https://music.wkczy.com:1443/rest/stream.view?id=be42794b41606a2e41d95db4f96b49c1&format=raw&u=wk224&t=1fe253d10e596efd339e50c46dbb84b4&s=l92vM&v=1.10.2&f=json&c=volusonic" took 9 milliseconds Jul 21 15:35:30 volumio volumio[1157]: verbose: ControllerMpd::parseState Jul 21 15:35:30 volumio volumio[1157]: verbose: ControllerMpd::sendMpdCommand play Jul 21 15:35:30 volumio volumio[1157]: info: [1721547330180] ControllerVolusonic::pushState Jul 21 15:35:30 volumio volumio[1157]: info: CoreCommandRouter::servicePushState Jul 21 15:35:30 volumio volumio[1157]: info: CoreStateMachine::pushState Jul 21 15:35:30 volumio volumio[1157]: info: CorePlayQueue::getTrack 1 Jul 21 15:35:30 volumio volumio[1157]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 21 15:35:30 volumio volumio[1157]: info: CoreCommandRouter::volumioPushState Jul 21 15:35:30 volumio volumio[1157]: info: CorePlayQueue::getTrack 1 Jul 21 15:35:30 volumio volumio[1157]: 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} Jul 21 15:35:30 volumio volumio[1157]: verbose: CURRENT POSITION 1 Jul 21 15:35:30 volumio volumio[1157]: info: CoreStateMachine::syncState stateService stop Jul 21 15:35:30 volumio volumio[1157]: info: CoreStateMachine::syncState currentStatus stop Jul 21 15:35:30 volumio volumio[1157]: info: CoreStateMachine::pushState Jul 21 15:35:30 volumio volumio[1157]: info: CorePlayQueue::getTrack 1 Jul 21 15:35:30 volumio volumio[1157]: info: CoreCommandRouter::volumioPushState Jul 21 15:35:30 volumio volumio[1157]: info: No code Jul 21 15:35:30 volumio volumio[1157]: info: CoreStateMachine::pushState Jul 21 15:35:30 volumio volumio[1157]: info: CorePlayQueue::getTrack 1 Jul 21 15:35:30 volumio volumio[1157]: info: CoreCommandRouter::volumioPushState Jul 21 15:35:30 volumio volumio[1157]: info: ------------------------------ 61ms Jul 21 15:35:30 volumio volumio[1157]: info: sendMpdCommand play took 53 milliseconds Jul 21 15:35:30 volumio volumio[1157]: info: ControllerMpd::getState Jul 21 15:35:30 volumio volumio[1157]: verbose: ControllerMpd::sendMpdCommand status Jul 21 15:35:30 volumio volumio[1157]: info: sendMpdCommand status took 11 milliseconds Jul 21 15:35:30 volumio volumio[1157]: verbose: ControllerMpd::parseState Jul 21 15:35:30 volumio volumio[1157]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 21 15:35:30 volumio volumio[1157]: info: sendMpdCommand playlistinfo took 2 milliseconds Jul 21 15:35:30 volumio volumio[1157]: verbose: ControllerMpd::parseTrackInfo Jul 21 15:35:30 volumio volumio[1157]: info: [1721547330250] ControllerVolusonic::pushState Jul 21 15:35:30 volumio volumio[1157]: info: CoreCommandRouter::servicePushState Jul 21 15:35:30 volumio volumio[1157]: info: CorePlayQueue::getTrack 1 Jul 21 15:35:30 volumio volumio[1157]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"stream.view?id=be42794b41606a2e41d95db4f96b49c1&format=raw&u=wk224&t=1fe253d10e596efd339e50c46dbb84b4&s=l92vM&v=1.10.2&f=json&c=volusonic","artist":null,"album":null,"uri":"https://music.wkczy.com:1443/rest/stream.view?id=be42794b41606a2e41d95db4f96b49c1&format=raw&u=wk224&t=1fe253d10e596efd339e50c46dbb84b4&s=l92vM&v=1.10.2&f=json&c=volusonic","trackType":""} Jul 21 15:35:30 volumio volumio[1157]: verbose: CURRENT POSITION 1 Jul 21 15:35:30 volumio volumio[1157]: info: CoreStateMachine::syncState stateService play Jul 21 15:35:30 volumio volumio[1157]: info: CoreStateMachine::syncState currentStatus stop Jul 21 15:35:30 volumio volumio[1157]: info: CoreCommandRouter::volumioGetState Jul 21 15:35:30 volumio volumio[1157]: info: CorePlayQueue::getTrack 1 Jul 21 15:35:31 volumio volumio[1157]: info: [1721547331165] ControllerVolusonic: MPD player state update Jul 21 15:35:31 volumio volumio[1157]: info: ControllerMpd::getState Jul 21 15:35:31 volumio volumio[1157]: verbose: ControllerMpd::sendMpdCommand status Jul 21 15:35:31 volumio volumio[1157]: info: Jul 21 15:35:31 volumio volumio[1157]: ---------------------------- MPD announces state update: player Jul 21 15:35:31 volumio volumio[1157]: info: ControllerMpd::getState Jul 21 15:35:31 volumio volumio[1157]: verbose: ControllerMpd::sendMpdCommand status Jul 21 15:35:31 volumio volumio[1157]: verbose: ControllerMpd::sendMpdCommand clearerror Jul 21 15:35:31 volumio volumio[1157]: info: sendMpdCommand status took 18 milliseconds Jul 21 15:35:31 volumio volumio[1157]: verbose: ControllerMpd::sendMpdCommand clearerror Jul 21 15:35:31 volumio volumio[1157]: info: sendMpdCommand status took 14 milliseconds Jul 21 15:35:31 volumio volumio[1157]: verbose: ControllerMpd::parseState Jul 21 15:35:31 volumio volumio[1157]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 21 15:35:31 volumio volumio[1157]: verbose: ControllerMpd::parseState Jul 21 15:35:31 volumio volumio[1157]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 21 15:35:31 volumio volumio[1157]: info: sendMpdCommand clearerror took 10 milliseconds Jul 21 15:35:31 volumio volumio[1157]: info: sendMpdCommand clearerror took 12 milliseconds Jul 21 15:35:31 volumio volumio[1157]: info: sendMpdCommand playlistinfo took 8 milliseconds Jul 21 15:35:31 volumio volumio[1157]: info: sendMpdCommand playlistinfo took 7 milliseconds Jul 21 15:35:31 volumio volumio[1157]: verbose: ControllerMpd::parseTrackInfo Jul 21 15:35:31 volumio volumio[1157]: verbose: ControllerMpd::parseTrackInfo Jul 21 15:35:31 volumio volumio[1157]: info: CorePlayQueue::getTrack 1 Jul 21 15:35:31 volumio volumio[1157]: info: [1721547331203] ControllerVolusonic::pushState Jul 21 15:35:31 volumio volumio[1157]: info: CoreCommandRouter::servicePushState Jul 21 15:35:31 volumio volumio[1157]: info: CoreStateMachine::pushState Jul 21 15:35:31 volumio volumio[1157]: info: CorePlayQueue::getTrack 1 Jul 21 15:35:31 volumio volumio[1157]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 21 15:35:31 volumio volumio[1157]: info: CoreCommandRouter::volumioPushState Jul 21 15:35:31 volumio volumio[1157]: info: CorePlayQueue::getTrack 1 Jul 21 15:35:31 volumio volumio[1157]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"stream.view?id=be42794b41606a2e41d95db4f96b49c1&format=raw&u=wk224&t=1fe253d10e596efd339e50c46dbb84b4&s=l92vM&v=1.10.2&f=json&c=volusonic","artist":null,"album":null,"uri":"https://music.wkczy.com:1443/rest/stream.view?id=be42794b41606a2e41d95db4f96b49c1&format=raw&u=wk224&t=1fe253d10e596efd339e50c46dbb84b4&s=l92vM&v=1.10.2&f=json&c=volusonic","trackType":""} Jul 21 15:35:31 volumio volumio[1157]: verbose: CURRENT POSITION 1 Jul 21 15:35:31 volumio volumio[1157]: info: CoreStateMachine::syncState stateService stop Jul 21 15:35:31 volumio volumio[1157]: info: CoreStateMachine::syncState currentStatus play Jul 21 15:35:31 volumio volumio[1157]: info: CoreStateMachine::play index undefined Jul 21 15:35:31 volumio volumio[1157]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 21 15:35:31 volumio volumio[1157]: info: CoreStateMachine::pushState Jul 21 15:35:31 volumio volumio[1157]: info: CorePlayQueue::getTrack 2 Jul 21 15:35:31 volumio volumio[1157]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 21 15:35:31 volumio volumio[1157]: info: CoreCommandRouter::volumioPushState Jul 21 15:35:31 volumio volumio[1157]: info: ControllerMpd::pushState Jul 21 15:35:31 volumio volumio[1157]: info: CoreCommandRouter::servicePushState Jul 21 15:35:31 volumio volumio[1157]: info: CoreStateMachine::pushState Jul 21 15:35:31 volumio volumio[1157]: info: CorePlayQueue::getTrack 2 Jul 21 15:35:31 volumio volumio[1157]: info: CoreCommandRouter::volumioPushState Jul 21 15:35:31 volumio volumio[1157]: info: CorePlayQueue::getTrack 2 Jul 21 15:35:31 volumio volumio[1157]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Jul 21 15:35:31 volumio volumio[1157]: info: CorePlayQueue::getTrack 2 Jul 21 15:35:31 volumio volumio[1157]: info: CoreStateMachine::startPlaybackTimer Jul 21 15:35:31 volumio volumio[1157]: info: CorePlayQueue::getTrack 2 Jul 21 15:35:31 volumio volumio[1157]: info: [1721547331224] ControllerVolusonic::clearAddPlayTrack Jul 21 15:35:31 volumio volumio[1157]: verbose: ControllerMpd::sendMpdCommand stop Jul 21 15:35:31 volumio volumio[1157]: info: ------------------------------ 59ms Jul 21 15:35:31 volumio volumio[1157]: info: CoreStateMachine::pushState Jul 21 15:35:31 volumio volumio[1157]: info: CorePlayQueue::getTrack 2 Jul 21 15:35:31 volumio volumio[1157]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 21 15:35:31 volumio volumio[1157]: info: CoreCommandRouter::volumioPushState Jul 21 15:35:31 volumio volumio[1157]: info: sendMpdCommand stop took 10 milliseconds Jul 21 15:35:31 volumio volumio[1157]: verbose: ControllerMpd::sendMpdCommand clear Jul 21 15:35:31 volumio volumio[1157]: info: [LastFM] Current track has sufficient metadata: title (Tárrega: Capricho árabe) and artist (Andrès Segovia) passed on explicitly Jul 21 15:35:31 volumio volumio[1157]: info: CoreCommandRouter::volumioGetQueue Jul 21 15:35:31 volumio volumio[1157]: info: CoreStateMachine::getQueue Jul 21 15:35:31 volumio volumio[1157]: info: CorePlayQueue::getQueue Jul 21 15:35:31 volumio volumio[1157]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 21 15:35:31 volumio volumio[1157]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Jul 21 15:35:31 volumio volumio[1157]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:71:26) { Jul 21 15:35:31 volumio volumio[1157]: errno: -16, Jul 21 15:35:31 volumio volumio[1157]: code: 'EBUSY', Jul 21 15:35:31 volumio volumio[1157]: syscall: 'getaddrinfo', Jul 21 15:35:31 volumio volumio[1157]: hostname: 'ws.audioscrobbler.com' Jul 21 15:35:31 volumio volumio[1157]: } Jul 21 15:35:31 volumio volumio[1157]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 21 15:35:31 volumio sudo[17145]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-21 15:34 Jul 21 15:35:31 volumio sudo[17145]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 21 15:35:31 volumio sudo[17145]: pam_unix(sudo:session): session closed for user root Jul 21 15:35:31 volumio volumio-remote-updater[756]: [2024-07-21 15:35:31] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jul 21 15:35:31 volumio volumio-remote-updater[756]: [2024-07-21 15:35:31] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jul 21 15:35:31 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jul 21 15:35:31 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jul 21 15:35:31 volumio systemd[1]: Started dynamicswap service. Jul 21 15:35:31 volumio systemd[1]: dynamicswap.service: Succeeded. Jul 21 15:35:32 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Jul 21 15:35:32 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 1. Jul 21 15:35:32 volumio systemd[1]: Stopped Volumio Backend Module. Jul 21 15:35:32 volumio systemd[1]: Started Volumio Backend Module. Jul 21 15:35:32 volumio systemd[1]: Started dynamicswap service. Jul 21 15:35:32 volumio systemd[1]: dynamicswap.service: Succeeded. Jul 21 15:35:33 volumio volumio[17158]: info: ------------------------------------------- Jul 21 15:35:33 volumio volumio[17158]: info: ----- Volumio3 ---- Jul 21 15:35:33 volumio volumio[17158]: info: ------------------------------------------- Jul 21 15:35:33 volumio volumio[17158]: info: ----- System startup ---- Jul 21 15:35:33 volumio volumio[17158]: info: ------------------------------------------- Jul 21 15:35:33 volumio dhcpcd[825]: wlan0: using static address 192.168.99.209/24 Jul 21 15:35:33 volumio avahi-daemon[730]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.99.209. Jul 21 15:35:33 volumio avahi-daemon[730]: New relevant interface wlan0.IPv4 for mDNS. Jul 21 15:35:33 volumio dhcpcd[825]: wlan0: adding route to 192.168.99.0/24 Jul 21 15:35:33 volumio avahi-daemon[730]: Registering new address record for 192.168.99.209 on wlan0.IPv4. Jul 21 15:35:33 volumio dhcpcd[825]: wlan0: adding default route via 192.168.99.1 Jul 21 15:35:33 volumio volumio[17158]: info: MYVOLUMIO Environment detected Jul 21 15:35:33 volumio volumio[17158]: info: Plugin folders cleanup Jul 21 15:35:33 volumio volumio[17158]: info: Scanning into folder /volumio/app/plugins/ Jul 21 15:35:33 volumio volumio[17158]: info: Scanning category audio_interface Jul 21 15:35:33 volumio volumio[17158]: info: Scanning category miscellanea Jul 21 15:35:33 volumio volumio[17158]: info: Scanning category music_service Jul 21 15:35:33 volumio volumio[17158]: info: Scanning category plugins.json Jul 21 15:35:33 volumio volumio[17158]: info: Scanning category system_controller Jul 21 15:35:33 volumio volumio[17158]: info: Scanning category user_interface Jul 21 15:35:33 volumio volumio[17158]: info: Scanning into folder /data/plugins/ Jul 21 15:35:33 volumio volumio[17158]: info: Scanning category music_service Jul 21 15:35:33 volumio volumio[17158]: info: Scanning category user_interface Jul 21 15:35:33 volumio volumio[17158]: info: Plugin folders cleanup completed Jul 21 15:35:33 volumio volumio[17158]: info: ------------------------------------------- Jul 21 15:35:33 volumio volumio[17158]: info: ----- Core plugins startup ---- Jul 21 15:35:33 volumio volumio[17158]: info: ------------------------------------------- Jul 21 15:35:33 volumio volumio[17158]: info: Loading plugins from folder /volumio/app/plugins/ Jul 21 15:35:33 volumio volumio[17158]: info: Adding plugin upnp to MyMusic Plugins Jul 21 15:35:33 volumio volumio[17158]: info: Adding plugin airplay_emulation to MyMusic Plugins Jul 21 15:35:33 volumio volumio[17158]: info: Adding plugin upnp_browser to MyMusic Plugins Jul 21 15:35:33 volumio volumio[17158]: info: Loading plugins from folder /data/plugins/ Jul 21 15:35:33 volumio volumio[17158]: info: Loading plugin "system"... Jul 21 15:35:33 volumio volumio[17158]: info: Loading plugin "appearance"... Jul 21 15:35:34 volumio volumio[17158]: info: Loading plugin "network"... Jul 21 15:35:34 volumio volumio[17158]: info: Refreshing Cached IP Addresses Jul 21 15:35:34 volumio sudo[17222]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 21 15:35:34 volumio sudo[17222]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 21 15:35:34 volumio volumio[17158]: info: Loading plugin "services"... Jul 21 15:35:34 volumio volumio[17158]: info: Loading plugin "alsa_controller"... Jul 21 15:35:34 volumio sudo[17222]: pam_unix(sudo:session): session closed for user root Jul 21 15:35:34 volumio sudo[17224]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 21 15:35:34 volumio sudo[17228]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jul 21 15:35:34 volumio sudo[17228]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 21 15:35:34 volumio sudo[17224]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 21 15:35:34 volumio sudo[17224]: pam_unix(sudo:session): session closed for user root Jul 21 15:35:34 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 21 15:35:34 volumio volumio[17158]: info: Loading plugin "wizard"... Jul 21 15:35:34 volumio volumio[17158]: info: Loading plugin "networkfs"... Jul 21 15:35:34 volumio volumio[17158]: info: Cannot mount NAS m4acg at system boot, trial number 1 ,retrying in 5 seconds Jul 21 15:35:34 volumio volumio[17158]: info: Cannot mount NAS m2 at system boot, trial number 1 ,retrying in 5 seconds Jul 21 15:35:34 volumio volumio[17158]: info: Cannot mount NAS DSD at system boot, trial number 1 ,retrying in 5 seconds Jul 21 15:35:34 volumio volumio[17158]: info: Starting Udev Watcher for removable devices Jul 21 15:35:34 volumio volumio[17158]: info: Ignoring mount for partition: boot Jul 21 15:35:34 volumio volumio[17158]: info: Ignoring mount for partition: volumio Jul 21 15:35:34 volumio volumio[17158]: info: Ignoring mount for partition: volumio_data Jul 21 15:35:34 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 21 15:35:34 volumio volumio[17158]: info: Loading plugin "volumio_command_line_client"... Jul 21 15:35:34 volumio volumio[17158]: info: Loading plugin "upnp"... Jul 21 15:35:34 volumio volumio[17158]: info: [1721547334896] Starting Upmpd Daemon Jul 21 15:35:34 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 21 15:35:34 volumio volumio[17158]: info: Loading plugin "my_music"... Jul 21 15:35:34 volumio volumio[17158]: info: Loading plugin "mpd"... Jul 21 15:35:35 volumio volumio[17158]: info: Loading plugin "upnp_browser"... Jul 21 15:35:35 volumio volumio[17158]: info: Loading plugin "alarm-clock"... Jul 21 15:35:35 volumio ntpd[910]: Listen normally on 5 wlan0 192.168.99.209:123 Jul 21 15:35:35 volumio ntpd[910]: new interface(s) found: waking up resolver Jul 21 15:35:35 volumio volumio[17158]: info: Loading plugin "airplay_emulation"... Jul 21 15:35:35 volumio volumio[17158]: info: Starting Shairport Sync Jul 21 15:35:35 volumio volumio[17158]: info: Loading plugin "last_100"... Jul 21 15:35:35 volumio volumio[17158]: info: Loading plugin "webradio"... Jul 21 15:35:35 volumio volumio[17158]: info: Loading plugin "i2s_dacs"... Jul 21 15:35:35 volumio volumio[17158]: info: I2S DAC not set, start Auto-detection Jul 21 15:35:35 volumio volumio[17158]: info: Loading plugin "volumiodiscovery"... Jul 21 15:35:35 volumio volumio[17158]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jul 21 15:35:35 volumio volumio[17158]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 21 15:35:35 volumio node[17158]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jul 21 15:35:35 volumio volumio[17158]: *** WARNING *** For more information see Jul 21 15:35:35 volumio volumio[17158]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jul 21 15:35:35 volumio volumio[17158]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 21 15:35:35 volumio volumio[17158]: *** WARNING *** For more information see Jul 21 15:35:35 volumio node[17158]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 21 15:35:35 volumio node[17158]: *** WARNING *** For more information see Jul 21 15:35:35 volumio node[17158]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jul 21 15:35:35 volumio node[17158]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 21 15:35:35 volumio node[17158]: *** WARNING *** For more information see Jul 21 15:35:35 volumio volumio[17158]: info: Applying required configuration parameters for plugin volumiodiscovery Jul 21 15:35:35 volumio volumio[17158]: info: Discovery: Started advertising with name: Volumio Jul 21 15:35:35 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 21 15:35:35 volumio volumio[17158]: info: Loading plugin "peppy_screensaver"... Jul 21 15:35:36 volumio volumio[17158]: info: Applying required configuration parameters for plugin peppy_screensaver Jul 21 15:35:36 volumio volumio[17158]: info: Loading plugin "outputs"... Jul 21 15:35:36 volumio volumio[17158]: info: Loading plugin "albumart"... Jul 21 15:35:36 volumio volumio[17158]: info: Plugin example_plugin is not enabled Jul 21 15:35:36 volumio volumio[17158]: info: Loading plugin "inputs"... Jul 21 15:35:36 volumio volumio[17158]: info: Loading plugin "updater_comm"... Jul 21 15:35:36 volumio volumio[17158]: Forking 1 albumart workers Jul 21 15:35:36 volumio volumio[17158]: info: Plugin mpdemulation is not enabled Jul 21 15:35:36 volumio volumio[17158]: info: Loading plugin "rest_api"... Jul 21 15:35:36 volumio volumio[17158]: info: Loading plugin "websocket"... Jul 21 15:35:36 volumio volumio[17158]: info: Starting Socket.io Server version 2.3.0 Jul 21 15:35:36 volumio volumio[17158]: info: Loading plugin "volusonic"... Jul 21 15:35:36 volumio volumio[17158]: Starting albumart workers Jul 21 15:35:36 volumio volumio-remote-updater[756]: [2024-07-21 15:35:36] [connect] Successful connection Jul 21 15:35:37 volumio sudo[17228]: pam_unix(sudo:session): session closed for user root Jul 21 15:35:37 volumio volumio[17158]: info: Applying required configuration parameters for plugin volusonic Jul 21 15:35:37 volumio volumio[17158]: info: Loading plugin "Systeminfo"... Jul 21 15:35:37 volumio volumio[17158]: info: Loading plugin "lastfm"... Jul 21 15:35:37 volumio volumio[17158]: info: Loading i18n strings for locale zh Jul 21 15:35:37 volumio volumio[17158]: Updating browse sources language Jul 21 15:35:37 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 21 15:35:37 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 21 15:35:37 volumio volumio[17158]: info: CoreCommandRouter::initPlayerControls Jul 21 15:35:37 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 21 15:35:37 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 21 15:35:37 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 21 15:35:37 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 21 15:35:37 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 21 15:35:37 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 21 15:35:37 volumio volumio[17158]: Express server listening on port 3000 Jul 21 15:35:37 volumio volumio[17158]: [Metrics] WebUI: 5s 88.64ms Jul 21 15:35:37 volumio volumio[17158]: info: Setting Device type: x86 Jul 21 15:35:37 volumio volumio[17158]: info: CoreStateMachine::resetVolumioState Jul 21 15:35:37 volumio volumio[17158]: info: CoreStateMachine::getcurrentVolume Jul 21 15:35:37 volumio volumio[17158]: info: CoreCommandRouter::volumioRetrievevolume Jul 21 15:35:37 volumio volumio[17158]: info: CoreStateMachine::pushState Jul 21 15:35:37 volumio volumio[17158]: info: CorePlayQueue::getTrack 0 Jul 21 15:35:37 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 21 15:35:37 volumio volumio[17158]: info: CoreCommandRouter::volumioPushState Jul 21 15:35:37 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 21 15:35:38 volumio volumio[17158]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Jul 21 15:35:38 volumio volumio[17158]: 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: 1 Jul 21 15:35:38 volumio volumio[17158]: 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: 2 Jul 21 15:35:38 volumio volumio[17158]: 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: 3 Jul 21 15:35:38 volumio volumio[17158]: verbose: New Socket.io Connection to 192.168.99.209 from 192.168.99.127 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_5_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.5 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 4 Jul 21 15:35:38 volumio volumio[17158]: verbose: New Socket.io Connection to 192.168.99.209 from 192.168.99.127 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_5_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.5 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 5 Jul 21 15:35:38 volumio volumio[17158]: 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 Jul 21 15:35:38 volumio volumio-remote-updater[756]: [2024-07-21 15:35:38] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1721547336 101 Jul 21 15:35:38 volumio volumio[17158]: 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: 7 Jul 21 15:35:38 volumio volumio[17158]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Jul 21 15:35:38 volumio volumio[17158]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Jul 21 15:35:38 volumio volumio[17158]: info: Reloading queue from file Jul 21 15:35:38 volumio volumio[17158]: info: CoreStateMachine::setRepeat false single undefined Jul 21 15:35:38 volumio volumio[17158]: info: CoreStateMachine::pushState Jul 21 15:35:38 volumio volumio[17158]: info: CorePlayQueue::getTrack 0 Jul 21 15:35:38 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 21 15:35:38 volumio volumio[17158]: info: CoreCommandRouter::volumioPushState Jul 21 15:35:38 volumio volumio[17158]: info: CoreStateMachine::setRandom false Jul 21 15:35:38 volumio volumio[17158]: info: CoreStateMachine::pushState Jul 21 15:35:38 volumio volumio[17158]: info: CorePlayQueue::getTrack 0 Jul 21 15:35:38 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 21 15:35:38 volumio volumio[17158]: info: CoreCommandRouter::volumioPushState Jul 21 15:35:38 volumio volumio[17158]: info: Completed loading Core Plugins Jul 21 15:35:38 volumio volumio[17158]: info: Preparing to generate the ALSA configuration file Jul 21 15:35:38 volumio volumio[17158]: info: The plugin peppy_screensaver has an ALSA contribution file Peppyalsa.postPeppyalsa.5.conf Jul 21 15:35:38 volumio volumio[17158]: info: Reading ALSA contributions from plugins. Jul 21 15:35:38 volumio volumio[17158]: info: CoreCommandRouter::volumioGetState Jul 21 15:35:38 volumio volumio[17158]: info: CorePlayQueue::getTrack 0 Jul 21 15:35:38 volumio volumio[17158]: info: Discovery: adding 3b8c1e6c-8086-4107-988a-19af26748b02 Jul 21 15:35:38 volumio volumio[17158]: info: Discovery: Found device Volumio Jul 21 15:35:38 volumio volumio[17158]: info: CoreCommandRouter::volumioGetState Jul 21 15:35:38 volumio volumio[17158]: info: CorePlayQueue::getTrack 0 Jul 21 15:35:38 volumio volumio[17158]: info: Asound.conf file unchanged, so no further update is needed Jul 21 15:35:38 volumio volumio[17158]: info: Output device has changed, restarting MPD Jul 21 15:35:38 volumio sudo[17282]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 21 15:35:38 volumio sudo[17282]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 21 15:35:38 volumio volumio[17158]: info: Output device has changed, restarting Shairport Sync Jul 21 15:35:38 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 21 15:35:38 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 21 15:35:38 volumio sudo[17282]: pam_unix(sudo:session): session closed for user root Jul 21 15:35:38 volumio sudo[17285]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 21 15:35:38 volumio sudo[17285]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 21 15:35:38 volumio ntpd[910]: Soliciting pool server 72.30.35.89 Jul 21 15:35:38 volumio systemd[1]: Stopping Music Player Daemon... Jul 21 15:35:38 volumio volumio[17158]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 21 15:35:38 volumio volumio[17158]: info: ___________ START PLUGINS ___________ Jul 21 15:35:38 volumio volumio[17158]: info: ControllerMpd::onStart: Initializing MPD Jul 21 15:35:38 volumio volumio[17158]: info: Creating MPD Configuration file Jul 21 15:35:38 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 21 15:35:38 volumio volumio[17158]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 21 15:35:38 volumio volumio[17158]: info: [1721547338451] CoreMusicLibrary::Adding element 媒体服务器 Jul 21 15:35:38 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 21 15:35:38 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 21 15:35:38 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 21 15:35:38 volumio sudo[17291]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 21 15:35:38 volumio sudo[17291]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 21 15:35:38 volumio sudo[17291]: pam_unix(sudo:session): session closed for user root Jul 21 15:35:38 volumio sudo[17293]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 21 15:35:38 volumio sudo[17293]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 21 15:35:38 volumio volumio[17158]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 21 15:35:38 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 21 15:35:38 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 21 15:35:38 volumio volumio[17158]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 21 15:35:38 volumio volumio[17158]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 21 15:35:38 volumio volumio[17158]: info: [1721547338599] CoreMusicLibrary::Adding element Last_100 Jul 21 15:35:38 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 21 15:35:38 volumio volumio[17158]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 21 15:35:38 volumio volumio[17158]: info: [1721547338604] CoreMusicLibrary::Adding element Webradio Jul 21 15:35:38 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 21 15:35:38 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 21 15:35:38 volumio volumio[17158]: info: Initializing BBC Radios Jul 21 15:35:38 volumio systemd[1]: mpd.service: Succeeded. Jul 21 15:35:38 volumio systemd[1]: Stopped Music Player Daemon. Jul 21 15:35:38 volumio volumio[17158]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Jul 21 15:35:38 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 21 15:35:38 volumio systemd[1]: Starting Music Player Daemon... Jul 21 15:35:38 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 21 15:35:38 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 21 15:35:38 volumio volumio[17158]: info: Loading i18n strings for locale zh Jul 21 15:35:38 volumio volumio[17158]: info: /tmp/myfifo created Jul 21 15:35:38 volumio sudo[17306]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jul 21 15:35:38 volumio sudo[17306]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 21 15:35:38 volumio sudo[17306]: pam_unix(sudo:session): session closed for user root Jul 21 15:35:38 volumio volumio[17158]: info: /tmp/myfifosa created Jul 21 15:35:38 volumio sudo[17322]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/modprobe snd-dummy index=7 pcm_substreams=1 fake_buffer=0 Jul 21 15:35:38 volumio sudo[17322]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 21 15:35:38 volumio sudo[17322]: pam_unix(sudo:session): session closed for user root Jul 21 15:35:38 volumio volumio[17158]: info: snd-dummy loaded Jul 21 15:35:38 volumio volumio[17158]: error: Plugin peppy_screensaver failed to start! Error: ENOTDIR: not a directory, scandir '/tmp/peppyrunning' Jul 21 15:35:38 volumio volumio[17158]: info: Loading i18n strings for locale zh Jul 21 15:35:38 volumio volumio[17158]: Updating browse sources language Jul 21 15:35:38 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 21 15:35:38 volumio volumio[17158]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 21 15:35:38 volumio volumio[17158]: info: [1721547338840] CoreMusicLibrary::Adding element Volusonic Jul 21 15:35:38 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 21 15:35:38 volumio volumio[17158]: Cannot find translation for source Volusonic Jul 21 15:35:38 volumio volumio[17158]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 21 15:35:38 volumio volumio[17158]: info: [1721547338845] CoreMusicLibrary::Adding element LastFM Jul 21 15:35:38 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 21 15:35:38 volumio volumio[17158]: Cannot find translation for source Volusonic Jul 21 15:35:38 volumio volumio[17158]: Cannot find translation for source LastFM Jul 21 15:35:38 volumio volumio[17158]: info: [LastFM] scrobbler initiated! Jul 21 15:35:38 volumio volumio[17158]: info: [LastFM] extended logging: false Jul 21 15:35:38 volumio volumio[17158]: info: [LastFM] try scrobble stream/radio plays: true Jul 21 15:35:38 volumio volumio[17158]: info: [LastFM] Left init routine Jul 21 15:35:38 volumio volumio[17158]: info: [LastFM] Socket already connected: false Jul 21 15:35:38 volumio volumio[17158]: info: Volumio Calling Home Jul 21 15:35:39 volumio volumio[17158]: verbose: New Socket.io Connection to 192.168.99.209 from 192.168.99.127 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_5_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.5 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 9 Jul 21 15:35:39 volumio volumio[17158]: info: MPD Permissions set Jul 21 15:35:39 volumio volumio[17158]: info: MPD Permissions set Jul 21 15:35:39 volumio volumio[17158]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Jul 21 15:35:39 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 21 15:35:39 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 21 15:35:39 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 21 15:35:39 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 21 15:35:39 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jul 21 15:35:39 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 21 15:35:39 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 21 15:35:39 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 21 15:35:39 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 21 15:35:39 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 21 15:35:39 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 21 15:35:39 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jul 21 15:35:39 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 21 15:35:39 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jul 21 15:35:39 volumio volumio[17158]: info: Starting Shairport Sync Jul 21 15:35:39 volumio volumio[17158]: info: Starting Shairport Sync Jul 21 15:35:39 volumio sudo[17346]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 21 15:35:39 volumio sudo[17346]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 21 15:35:39 volumio volumio[17158]: info: Starting Shairport Sync Jul 21 15:35:39 volumio sudo[17349]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 21 15:35:39 volumio sudo[17349]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 21 15:35:39 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jul 21 15:35:39 volumio systemd[1]: shairport-sync.service: Succeeded. Jul 21 15:35:39 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jul 21 15:35:39 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jul 21 15:35:39 volumio sudo[17346]: pam_unix(sudo:session): session closed for user root Jul 21 15:35:39 volumio volumio[17158]: info: CoreCommandRouter::volumioGetVisibleSources Jul 21 15:35:39 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 21 15:35:39 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jul 21 15:35:39 volumio volumio[17158]: info: CoreCommandRouter::volumioGetState Jul 21 15:35:39 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Jul 21 15:35:39 volumio systemd[1]: shairport-sync.service: Succeeded. Jul 21 15:35:39 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jul 21 15:35:39 volumio volumio[17158]: info: CorePlayQueue::getTrack 0 Jul 21 15:35:39 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jul 21 15:35:39 volumio sudo[17352]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 21 15:35:39 volumio sudo[17352]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 21 15:35:39 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jul 21 15:35:39 volumio volumio[17158]: info: Received Get System Info Jul 21 15:35:39 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 21 15:35:39 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 21 15:35:39 volumio volumio[17158]: info: Discovery: Getting this device information Jul 21 15:35:39 volumio volumio[17158]: info: CoreCommandRouter::volumioGetState Jul 21 15:35:39 volumio volumio[17158]: info: CorePlayQueue::getTrack 0 Jul 21 15:35:39 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 21 15:35:39 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jul 21 15:35:39 volumio sudo[17349]: pam_unix(sudo:session): session closed for user root Jul 21 15:35:39 volumio volumio[17158]: info: CoreCommandRouter::volumioGetState Jul 21 15:35:39 volumio volumio[17158]: info: CorePlayQueue::getTrack 0 Jul 21 15:35:39 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jul 21 15:35:39 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Jul 21 15:35:39 volumio systemd[1]: shairport-sync.service: Succeeded. Jul 21 15:35:39 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jul 21 15:35:39 volumio volumio[17158]: info: Listing playlists Jul 21 15:35:39 volumio volumio[17158]: info: CoreCommandRouter::volumioGetQueue Jul 21 15:35:39 volumio volumio[17158]: info: CoreStateMachine::getQueue Jul 21 15:35:39 volumio volumio[17158]: info: CorePlayQueue::getQueue Jul 21 15:35:39 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jul 21 15:35:39 volumio sudo[17352]: pam_unix(sudo:session): session closed for user root Jul 21 15:35:39 volumio volumio[17158]: info: [LastFM] finished init: Authenticated successfully! Jul 21 15:35:39 volumio volumio[17158]: info: Shairport-Sync Started Jul 21 15:35:39 volumio volumio[17158]: Error adding Membership: Error: addMembership EINVAL Jul 21 15:35:39 volumio volumio[17158]: info: Shairport-Sync Started Jul 21 15:35:39 volumio volumio[17158]: info: Shairport-Sync Started Jul 21 15:35:39 volumio volumio[17158]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Jul 21 15:35:39 volumio volumio[17158]: info: CoreCommandRouter::volumioGetState Jul 21 15:35:39 volumio volumio[17158]: info: CorePlayQueue::getTrack 0 Jul 21 15:35:39 volumio mpd[17319]: Jul 21 15:35 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jul 21 15:35:39 volumio volumio[17158]: info: Cannot mount NAS m4acg at system boot, trial number 2 ,retrying in 5 seconds Jul 21 15:35:39 volumio volumio[17158]: info: Cannot mount NAS m2 at system boot, trial number 2 ,retrying in 5 seconds Jul 21 15:35:39 volumio volumio[17158]: info: Cannot mount NAS DSD at system boot, trial number 2 ,retrying in 5 seconds Jul 21 15:35:39 volumio volumio[17158]: info: Volumio called home Jul 21 15:35:41 volumio volumio[17158]: 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: 12 Jul 21 15:35:41 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jul 21 15:35:41 volumio volumio[17158]: info: CoreCommandRouter::volumioGetVisibleSources Jul 21 15:35:41 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 21 15:35:41 volumio volumio[17158]: info: CoreCommandRouter::volumioGetState Jul 21 15:35:41 volumio volumio[17158]: info: CorePlayQueue::getTrack 0 Jul 21 15:35:41 volumio volumio[17158]: info: CoreCommandRouter::volumioGetState Jul 21 15:35:41 volumio volumio[17158]: info: CorePlayQueue::getTrack 0 Jul 21 15:35:41 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jul 21 15:35:41 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jul 21 15:35:41 volumio volumio[17158]: info: Received Get System Info Jul 21 15:35:41 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 21 15:35:41 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 21 15:35:41 volumio volumio[17158]: info: Discovery: Getting this device information Jul 21 15:35:41 volumio volumio[17158]: info: CoreCommandRouter::volumioGetState Jul 21 15:35:41 volumio volumio[17158]: info: CorePlayQueue::getTrack 0 Jul 21 15:35:41 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 21 15:35:41 volumio volumio[17158]: info: CoreCommandRouter::volumioGetState Jul 21 15:35:41 volumio volumio[17158]: info: CorePlayQueue::getTrack 0 Jul 21 15:35:41 volumio volumio[17158]: info: Listing playlists Jul 21 15:35:41 volumio systemd[1]: Started Music Player Daemon. Jul 21 15:35:41 volumio sudo[17293]: pam_unix(sudo:session): session closed for user root Jul 21 15:35:41 volumio sudo[17285]: pam_unix(sudo:session): session closed for user root Jul 21 15:35:41 volumio volumio[17158]: info: Completed starting Core Plugins Jul 21 15:35:41 volumio volumio[17158]: info: ------------------------------------------- Jul 21 15:35:41 volumio volumio[17158]: info: ----- MyVolumio plugins startup ---- Jul 21 15:35:41 volumio volumio[17158]: info: ------------------------------------------- Jul 21 15:35:41 volumio volumio[17158]: info: [MyVolumio PluginManager] Fetching plans data.... Jul 21 15:35:41 volumio volumio[17158]: error: MPD error: The expression evaluated to a falsy value: Jul 21 15:35:41 volumio volumio[17158]: assert.ok(self.idling) Jul 21 15:35:41 volumio volumio[17158]: error: The expression evaluated to a falsy value: Jul 21 15:35:41 volumio volumio[17158]: assert.ok(self.idling) Jul 21 15:35:41 volumio volumio[17158]: info: MPD running with PID17319 Jul 21 15:35:41 volumio volumio[17158]: ,establishing connection Jul 21 15:35:41 volumio volumio[17158]: error: MPD error: The expression evaluated to a falsy value: Jul 21 15:35:41 volumio volumio[17158]: assert.ok(self.idling) Jul 21 15:35:41 volumio volumio[17158]: error: The expression evaluated to a falsy value: Jul 21 15:35:41 volumio volumio[17158]: assert.ok(self.idling) Jul 21 15:35:41 volumio volumio[17158]: error: updateQueue error: null Jul 21 15:35:44 volumio volumio[17158]: info: Cannot mount NAS m4acg at system boot, trial number 3 ,retrying in 5 seconds Jul 21 15:35:44 volumio volumio[17158]: info: Cannot mount NAS m2 at system boot, trial number 3 ,retrying in 5 seconds Jul 21 15:35:44 volumio volumio[17158]: info: Cannot mount NAS DSD at system boot, trial number 3 ,retrying in 5 seconds Jul 21 15:35:44 volumio sudo[17368]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 21 15:35:44 volumio sudo[17368]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 21 15:35:44 volumio sudo[17370]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 21 15:35:44 volumio sudo[17370]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 21 15:35:44 volumio sudo[17370]: pam_unix(sudo:session): session closed for user root Jul 21 15:35:44 volumio sudo[17368]: pam_unix(sudo:session): session closed for user root Jul 21 15:35:44 volumio sudo[17376]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jul 21 15:35:44 volumio sudo[17376]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 21 15:35:45 volumio sudo[17376]: pam_unix(sudo:session): session closed for user root Jul 21 15:35:45 volumio volumio[17158]: info: Upmpdcli Daemon Started Jul 21 15:35:49 volumio volumio[17158]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jul 21 15:35:49 volumio volumio[17158]: info: Cannot mount NAS m4acg at system boot, trial number 4 ,retrying in 5 seconds Jul 21 15:35:49 volumio volumio[17158]: info: Cannot mount NAS m2 at system boot, trial number 4 ,retrying in 5 seconds Jul 21 15:35:49 volumio volumio[17158]: info: Cannot mount NAS DSD at system boot, trial number 4 ,retrying in 5 seconds Jul 21 15:35:51 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 21 15:35:51 volumio volumio[17158]: info: Preload queue cleared Jul 21 15:35:55 volumio volumio[17158]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Jul 21 15:35:55 volumio volumio[17158]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Jul 21 15:35:55 volumio volumio[17158]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Jul 21 15:35:55 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 21 15:35:57 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 21 15:36:00 volumio ntpd[910]: Soliciting pool server 134.215.155.177 Jul 21 15:36:00 volumio volumio[17158]: info: Preload queue cleared Jul 21 15:36:02 volumio volumio[17158]: info: Preload queue cleared Jul 21 15:36:02 volumio volumio[17158]: error: MyVolumio Plugin failed to start in a timely fashion Jul 21 15:36:02 volumio volumio[17158]: info: BOOT COMPLETED Jul 21 15:36:02 volumio volumio[17158]: [Metrics] CommandRouter: 28s 988.47ms Jul 21 15:36:02 volumio volumio[17158]: info: CoreCommandRouter::volumiosetStartupVolume Jul 21 15:36:02 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 21 15:36:02 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 21 15:36:02 volumio volumio[17158]: info: CoreCommandRouter::Close All Modals sent Jul 21 15:36:02 volumio volumio[17158]: info: CoreCommandRouter::Close All Modals sent Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jul 21 15:36:04 volumio volumio[17158]: info: Adding plugin bluetooth to MyMusic Plugins Jul 21 15:36:04 volumio volumio[17158]: info: Adding plugin multiroom to MyMusic Plugins Jul 21 15:36:04 volumio volumio[17158]: info: Adding plugin metavolumio to MyMusic Plugins Jul 21 15:36:04 volumio volumio[17158]: info: Adding plugin cd_controller to MyMusic Plugins Jul 21 15:36:04 volumio volumio[17158]: info: Adding plugin smart_inputs to MyMusic Plugins Jul 21 15:36:04 volumio volumio[17158]: info: Adding plugin tidalconnect to MyMusic Plugins Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jul 21 15:36:04 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 21 15:36:04 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 21 15:36:04 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 21 15:36:04 volumio volumio[17158]: info: Starting MyVolumio Remote Streaming Endpoints Jul 21 15:36:04 volumio volumio[17158]: info: MyVolumio login type: Token Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jul 21 15:36:04 volumio volumio[17158]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jul 21 15:36:05 volumio volumio[17158]: info: Starting Streaming Service Transparent Proxy Jul 21 15:36:05 volumio volumio[17158]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jul 21 15:36:05 volumio volumio[17158]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jul 21 15:36:05 volumio volumio[17158]: info: Streaming services startup Jul 21 15:36:05 volumio volumio[17158]: info: Starting Streaming Daemon Jul 21 15:36:05 volumio sudo[17442]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jul 21 15:36:05 volumio sudo[17442]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 21 15:36:05 volumio sudo[17442]: pam_unix(sudo:session): session closed for user root Jul 21 15:36:05 volumio volumio[17158]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jul 21 15:36:05 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jul 21 15:36:05 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 21 15:36:05 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jul 21 15:36:06 volumio volumio[17158]: STREAMING PROXY: Starting server on port 3245 Jul 21 15:36:06 volumio volumio[17158]: Node JS runtime: 14 Jul 21 15:36:06 volumio volumio[17158]: error: Cannot start Volumio Streaming Daemon Jul 21 15:36:06 volumio volumio[17158]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jul 21 15:36:06 volumio volumio[17158]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jul 21 15:36:07 volumio ntpd[910]: Soliciting pool server 162.159.200.123 Jul 21 15:36:08 volumio ntpd[910]: Soliciting pool server 204.93.207.12 Jul 21 15:36:09 volumio volumio[17158]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Jul 21 15:36:09 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 21 15:36:09 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 21 15:36:09 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 21 15:36:09 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jul 21 15:36:10 volumio volumio[17158]: info: CoreCommandRouter::volumioPlay Jul 21 15:36:10 volumio volumio[17158]: info: CoreStateMachine::play index 1 Jul 21 15:36:10 volumio volumio[17158]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 21 15:36:10 volumio volumio[17158]: info: CoreStateMachine::stop Jul 21 15:36:10 volumio volumio[17158]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 21 15:36:10 volumio volumio[17158]: info: CoreStateMachine::play index undefined Jul 21 15:36:10 volumio volumio[17158]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 21 15:36:10 volumio volumio[17158]: info: CorePlayQueue::getTrack 1 Jul 21 15:36:10 volumio volumio[17158]: info: CoreStateMachine::startPlaybackTimer Jul 21 15:36:10 volumio volumio[17158]: info: CorePlayQueue::getTrack 1 Jul 21 15:36:10 volumio volumio[17158]: info: [1721547370855] ControllerVolusonic::clearAddPlayTrack Jul 21 15:36:10 volumio volumio[17158]: verbose: ControllerMpd::sendMpdCommand stop Jul 21 15:36:14 volumio volumio[17158]: error: MyVolumio Custom Token format not valid, refreshing it Jul 21 15:36:15 volumio volumio[17158]: 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: 8 Jul 21 15:36:18 volumio volumio-remote-updater[756]: No test mode Jul 21 15:36:18 volumio volumio-remote-updater[756]: No alpha test mode Jul 21 15:36:18 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jul 21 15:36:18 volumio volumio[17158]: 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: 8 Jul 21 15:36:20 volumio volumio[17158]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Jul 21 15:36:20 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jul 21 15:36:20 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 21 15:36:21 volumio volumio[17158]: 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: 9 Jul 21 15:36:23 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 21 15:36:24 volumio volumio[17158]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Jul 21 15:36:25 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 21 15:36:25 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jul 21 15:36:25 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jul 21 15:36:25 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jul 21 15:36:25 volumio volumio[17158]: info: CoreCommandRouter::volumioGetBrowseSources Jul 21 15:36:25 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 21 15:36:27 volumio volumio[17158]: 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: 11 Jul 21 15:36:30 volumio volumio[17158]: info: MyVolumio login type: Token Jul 21 15:36:30 volumio volumio[17158]: info: CoreCommandRouter::volumioGetState Jul 21 15:36:30 volumio volumio[17158]: info: CorePlayQueue::getTrack 1 Jul 21 15:36:30 volumio volumio[17158]: info: Preload queue cleared Jul 21 15:36:33 volumio volumio[17158]: 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: 12 Jul 21 15:36:45 volumio volumio[17158]: 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: 13 Jul 21 15:36:45 volumio volumio[17158]: 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: 14 Jul 21 15:36:47 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 21 15:36:49 volumio volumio[17158]: 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: 14 Jul 21 15:36:52 volumio volumio[17158]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jul 21 15:36:52 volumio volumio[17158]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jul 21 15:36:56 volumio volumio[17158]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 21 15:36:56 volumio volumio[17158]: TypeError: Cannot read property 'length' of undefined Jul 21 15:36:56 volumio volumio[17158]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Jul 21 15:36:56 volumio volumio[17158]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Jul 21 15:36:56 volumio volumio[17158]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Jul 21 15:36:56 volumio volumio[17158]: at Parser.emit (events.js:400:28) Jul 21 15:36:56 volumio volumio[17158]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Jul 21 15:36:56 volumio volumio[17158]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Jul 21 15:36:56 volumio volumio[17158]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Jul 21 15:36:56 volumio volumio[17158]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Jul 21 15:36:56 volumio volumio[17158]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Jul 21 15:36:56 volumio volumio[17158]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Jul 21 15:36:56 volumio volumio[17158]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Jul 21 15:36:56 volumio volumio[17158]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Jul 21 15:36:56 volumio volumio[17158]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Jul 21 15:36:56 volumio volumio[17158]: at IncomingMessage.emit (events.js:412:35) Jul 21 15:36:56 volumio volumio[17158]: at endReadableNT (internal/streams/readable.js:1333:12) Jul 21 15:36:56 volumio volumio[17158]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Jul 21 15:36:56 volumio volumio[17158]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 21 15:36:56 volumio sudo[17512]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-21 15:35 Jul 21 15:36:56 volumio sudo[17512]: 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="4b122b2365bb8c09786cd63b50d1ea6db780eb4e" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 04 Jun 2024 09:13:11 PM CEST" VOLUMIO_VERSION="3.703" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="ac782621640fcc70c07e91a81b6d958b"