-- 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"