-- Logs begin at Sun 2024-04-14 12:32:30 CEST, end at Sun 2024-04-14 12:43:39 CEST. --
Apr 14 12:42:01 volumio volumio[2234]: info: Tunnel connection is inactive, restarting it
Apr 14 12:42:01 volumio volumio[2234]: info: Starting Tunnel 1
Apr 14 12:42:01 volumio volumio[2234]: info: Starting Tunnel Connection Checker
Apr 14 12:42:01 volumio sudo[2751]: volumio : unable to resolve host volumio
Apr 14 12:42:01 volumio sudo[2751]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
Apr 14 12:42:01 volumio sudo[2751]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service
Apr 14 12:42:01 volumio sudo[2751]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 14 12:42:01 volumio autossh[2575]: received signal to exit (15)
Apr 14 12:42:01 volumio systemd[1]: Stopping MyVolumio SSH Tunnel...
Apr 14 12:42:01 volumio systemd[1]: sshtunnel.service: Main process exited, code=killed, status=15/TERM
Apr 14 12:42:01 volumio systemd[1]: sshtunnel.service: Succeeded.
Apr 14 12:42:01 volumio systemd[1]: Stopped MyVolumio SSH Tunnel.
Apr 14 12:42:01 volumio systemd[1]: Started MyVolumio SSH Tunnel.
Apr 14 12:42:01 volumio sudo[2751]: pam_unix(sudo:session): session closed for user root
Apr 14 12:42:01 volumio volumio[2234]: info: Remote SSH Started
Apr 14 12:42:01 volumio autossh[2754]: port set to 0, monitoring disabled
Apr 14 12:42:01 volumio autossh[2754]: starting ssh (count 1)
Apr 14 12:42:01 volumio autossh[2754]: ssh child pid is 2757
Apr 14 12:42:02 volumio volumio[2234]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7
Apr 14 12:42:02 volumio volumio[2234]: info: CoreCommandRouter::volumioGetState
Apr 14 12:42:02 volumio volumio[2234]: info: CorePlayQueue::getTrack 0
Apr 14 12:42:02 volumio volumiossh-tunnel[2753]: Warning: Permanently added '[eu4.myvolumio.org]:2222,[167.172.103.77]:2222' (RSA) to the list of known hosts.
Apr 14 12:42:23 volumio volumio[2234]: info: CoreCommandRouter::volumioGetState
Apr 14 12:42:23 volumio volumio[2234]: info: CorePlayQueue::getTrack 0
Apr 14 12:42:24 volumio volumio[2234]: info: CoreCommandRouter::volumioPlay
Apr 14 12:42:24 volumio volumio[2234]: info: CoreStateMachine::play index undefined
Apr 14 12:42:24 volumio volumio[2234]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 14 12:42:24 volumio volumio[2234]: info: CorePlayQueue::getTrack 0
Apr 14 12:42:24 volumio volumio[2234]: info: CoreStateMachine::startPlaybackTimer
Apr 14 12:42:24 volumio volumio[2234]: info: CorePlayQueue::getTrack 0
Apr 14 12:42:24 volumio volumio[2234]: info: [1713091344611] ControllerTidal::clearAddPlayTrack
Apr 14 12:42:24 volumio volumio[2234]: info: Getting stream with soundQuality HI_RES
Apr 14 12:42:24 volumio volumio[2234]: verbose: ControllerMpd::sendMpdCommand stop
Apr 14 12:42:24 volumio volumio[2234]: info: sendMpdCommand stop took 4 milliseconds
Apr 14 12:42:24 volumio volumio[2234]: verbose: ControllerMpd::sendMpdCommand clear
Apr 14 12:42:24 volumio volumio[2234]: info:
Apr 14 12:42:24 volumio volumio[2234]: ---------------------------- MPD announces system playlist update
Apr 14 12:42:24 volumio volumio[2234]: info: Ignoring MPD Status Update
Apr 14 12:42:24 volumio volumio[2234]: info: sendMpdCommand clear took 6 milliseconds
Apr 14 12:42:24 volumio volumio[2234]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/205573155&soundQuality=HI_RES"
Apr 14 12:42:24 volumio volumio[2234]: error: updateQueue error: null
Apr 14 12:42:24 volumio volumio[2234]: info:
Apr 14 12:42:24 volumio volumio[2234]: ---------------------------- MPD announces system playlist update
Apr 14 12:42:24 volumio volumio[2234]: info: Ignoring MPD Status Update
Apr 14 12:42:24 volumio volumio[2234]: info: ------------------------------ 12ms
Apr 14 12:42:24 volumio volumio[2234]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/205573155&soundQuality=HI_RES" took 7 milliseconds
Apr 14 12:42:24 volumio volumio[2234]: info: CoreStateMachine::setConsumeUpdateService mpd
Apr 14 12:42:24 volumio volumio[2234]: verbose: ControllerMpd::sendMpdCommand play
Apr 14 12:42:24 volumio volumio[2234]: info: ------------------------------ 11ms
Apr 14 12:42:24 volumio volumio[2234]: info: sendMpdCommand play took 7 milliseconds
Apr 14 12:42:24 volumio volumio[2234]: STREAMING PROXY: Handling url /?data=tidal://song/205573155&soundQuality=HI_RES
Apr 14 12:42:24 volumio volumio[2234]: info: Executing endpoint getStreamUrltidal
Apr 14 12:42:24 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI
Apr 14 12:42:25 volumio volumio[2234]: info: Executing endpoint metavolumio
Apr 14 12:42:25 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 14 12:42:25 volumio volumio[2234]: info: Executing endpoint metavolumio
Apr 14 12:42:25 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 14 12:42:25 volumio volumio[2234]: info: Executing endpoint metavolumio
Apr 14 12:42:25 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 14 12:42:25 volumio volumio[2234]: info: getStreamUrl took 777 milliseconds
Apr 14 12:42:25 volumio volumio[2234]: STREAMING PROXY: Got real url: http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInMThhMWM1ZDExYTM0Y2QzN2JlOTZkNmU3Zjc3ODdiMzhfNjIubXA0/0.flac?token=1713094935~YWRjMzYwYjk2YTFjYzAyNDBlMjE0NmJiNDg3NTU2ZTI4YmIwMTZhZQ==
Apr 14 12:42:25 volumio volumio[2234]: STREAMING PROXY: Response: 200, length: 41511440
Apr 14 12:42:25 volumio volumio[2234]: info:
Apr 14 12:42:25 volumio volumio[2234]: ---------------------------- MPD announces state update: player
Apr 14 12:42:25 volumio volumio[2234]: info: ControllerMpd::getState
Apr 14 12:42:25 volumio volumio[2234]: verbose: ControllerMpd::sendMpdCommand status
Apr 14 12:42:25 volumio volumio[2234]: info:
Apr 14 12:42:25 volumio volumio[2234]: ---------------------------- MPD announces state update: player
Apr 14 12:42:25 volumio volumio[2234]: info: sendMpdCommand status took 26 milliseconds
Apr 14 12:42:25 volumio volumio[2234]: info: ControllerMpd::getState
Apr 14 12:42:25 volumio volumio[2234]: verbose: ControllerMpd::sendMpdCommand status
Apr 14 12:42:25 volumio volumio[2234]: verbose: ControllerMpd::parseState
Apr 14 12:42:25 volumio volumio[2234]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 14 12:42:25 volumio volumio[2234]: info: sendMpdCommand status took 10 milliseconds
Apr 14 12:42:25 volumio volumio[2234]: info: sendMpdCommand playlistinfo took 7 milliseconds
Apr 14 12:42:25 volumio volumio[2234]: verbose: ControllerMpd::parseState
Apr 14 12:42:25 volumio volumio[2234]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 14 12:42:25 volumio volumio[2234]: verbose: ControllerMpd::parseTrackInfo
Apr 14 12:42:25 volumio volumio[2234]: info: ControllerMpd::pushState
Apr 14 12:42:25 volumio volumio[2234]: info: CoreCommandRouter::servicePushState
Apr 14 12:42:25 volumio volumio[2234]: info: CorePlayQueue::getTrack 0
Apr 14 12:42:25 volumio volumio[2234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":225,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"205573155&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/205573155&soundQuality=HI_RES","trackType":"tidal"}
Apr 14 12:42:25 volumio volumio[2234]: verbose: CURRENT POSITION 0
Apr 14 12:42:25 volumio volumio[2234]: info: CoreStateMachine::syncState stateService play
Apr 14 12:42:25 volumio volumio[2234]: info: CoreStateMachine::syncState currentStatus stop
Apr 14 12:42:25 volumio volumio[2234]: info: ------------------------------ 63ms
Apr 14 12:42:25 volumio volumio[2234]: info: sendMpdCommand playlistinfo took 16 milliseconds
Apr 14 12:42:25 volumio volumio[2234]: verbose: ControllerMpd::parseTrackInfo
Apr 14 12:42:25 volumio volumio[2234]: info: ControllerMpd::pushState
Apr 14 12:42:25 volumio volumio[2234]: info: CoreCommandRouter::servicePushState
Apr 14 12:42:25 volumio volumio[2234]: info: CorePlayQueue::getTrack 0
Apr 14 12:42:25 volumio volumio[2234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":225,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"205573155&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/205573155&soundQuality=HI_RES","trackType":"tidal"}
Apr 14 12:42:25 volumio volumio[2234]: verbose: CURRENT POSITION 0
Apr 14 12:42:25 volumio volumio[2234]: info: CoreStateMachine::syncState stateService play
Apr 14 12:42:25 volumio volumio[2234]: info: CoreStateMachine::syncState currentStatus play
Apr 14 12:42:25 volumio volumio[2234]: info: Received an update from plugin. extracting info from payload
Apr 14 12:42:25 volumio volumio[2234]: info: CoreStateMachine::pushState
Apr 14 12:42:25 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 14 12:42:25 volumio volumio[2234]: info: CoreCommandRouter::volumioPushState
Apr 14 12:42:25 volumio volumio[2234]: info: CoreStateMachine::pushState
Apr 14 12:42:25 volumio volumio[2234]: info: CoreCommandRouter::volumioPushState
Apr 14 12:42:25 volumio volumio[2234]: info: ------------------------------ 146ms
Apr 14 12:42:25 volumio volumio[2234]: info: [LastFM] Current track has sufficient metadata: title (Easy On Me) and artist (Adele) passed on explicitly
Apr 14 12:42:26 volumio volumio[2234]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"Easy On ME","url":"https://www.last.fm/music/Adele/_/Easy+On+ME","duration":"0","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"773707","playcount":"8979864","artist":{"name":"Adele","mbid":"cc2c9c3c-b7bc-4b8b-84d8-4fbd8779e493","url":"https://www.last.fm/music/Adele"},"userplaycount":"11","userloved":"0","toptags":{"tag":[{"name":"2021","url":"https://www.last.fm/tag/2021"},{"name":"pop","url":"https://www.last.fm/tag/pop"},{"name":"Adele","url":"https://www.last.fm/tag/Adele"},{"name":"soul","url":"https://www.last.fm/tag/soul"},{"name":"piano","url":"https://www.last.fm/tag/piano"}]},"wiki":{"published":"14 Oct 2021, 20:52","summary":"\"Easy on Me\" is a plea to take it easy with someone who hasn't had the same chance to make their own decisions or experience the world. The lyrics imply that the singer was unable to explore the world around them due to their circumstances and had to go with the choices that were made for them. The singer is asking for the other person to not be too hard on them and to accept that they were still learning. The bridge hints at how the singer has had good intentions and hopeful outcomes Read more on Last.fm.","content":"\"Easy on Me\" is a plea to take it easy with someone who hasn't had the same chance to make their own decisions or experience the world. The lyrics imply that the singer was unable to explore the world around them due to their circumstances and had to go with the choices that were made for them. The singer is asking for the other person to not be too hard on them and to accept that they were still learning. The bridge hints at how the singer has had good intentions and hopeful outcomes, and though it may not show right now, they still want to be taken into account. Read more on Last.fm. User-contributed text is available under the Creative Commons By-SA License; additional terms may apply."}}}
Apr 14 12:42:27 volumio volumio[2234]: STREAMING PROXY: Client dropped request, destroying
Apr 14 12:42:30 volumio volumio[2234]: info: CoreCommandRouter::volumioNext
Apr 14 12:42:30 volumio volumio[2234]: info: CoreStateMachine::next
Apr 14 12:42:30 volumio volumio[2234]: info: [1713091350272] ControllerTidal::next
Apr 14 12:42:30 volumio volumio[2234]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 14 12:42:30 volumio volumio[2234]: info: CoreStateMachine::next
Apr 14 12:42:30 volumio volumio[2234]: info: CoreStateMachine::stop
Apr 14 12:42:30 volumio volumio[2234]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 14 12:42:30 volumio volumio[2234]: info: CoreStateMachine::stPlaybackTimer
Apr 14 12:42:30 volumio volumio[2234]: info: CoreStateMachine::updateTrackBlock
Apr 14 12:42:30 volumio volumio[2234]: info: CorePlayQueue::getTrackBlock
Apr 14 12:42:30 volumio volumio[2234]: info: CoreStateMachine::pushState
Apr 14 12:42:30 volumio volumio[2234]: info: CorePlayQueue::getTrack 0
Apr 14 12:42:30 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 14 12:42:30 volumio volumio[2234]: info: CoreCommandRouter::volumioPushState
Apr 14 12:42:30 volumio volumio[2234]: info: CoreStateMachine::serviceStop
Apr 14 12:42:30 volumio volumio[2234]: info: CorePlayQueue::getTrack 0
Apr 14 12:42:30 volumio volumio[2234]: info: CoreCommandRouter::serviceStop
Apr 14 12:42:30 volumio volumio[2234]: info: [1713091350307] ControllerTidal::stop
Apr 14 12:42:30 volumio volumio[2234]: info: CoreStateMachine::setConsumeUpdateService mpd
Apr 14 12:42:30 volumio volumio[2234]: info: ControllerMpd::stop
Apr 14 12:42:30 volumio volumio[2234]: verbose: ControllerMpd::sendMpdCommand stop
Apr 14 12:42:30 volumio volumio[2234]: info:
Apr 14 12:42:30 volumio volumio[2234]: ---------------------------- MPD announces state update: player
Apr 14 12:42:30 volumio volumio[2234]: info: sendMpdCommand stop took 38 milliseconds
Apr 14 12:42:30 volumio volumio[2234]: info: ControllerMpd::getState
Apr 14 12:42:30 volumio volumio[2234]: verbose: ControllerMpd::sendMpdCommand status
Apr 14 12:42:30 volumio volumio[2234]: info: CoreStateMachine::play index undefined
Apr 14 12:42:30 volumio volumio[2234]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 14 12:42:30 volumio volumio[2234]: info: CorePlayQueue::getTrack 1
Apr 14 12:42:30 volumio volumio[2234]: info: CoreStateMachine::startPlaybackTimer
Apr 14 12:42:30 volumio volumio[2234]: info: CorePlayQueue::getTrack 1
Apr 14 12:42:30 volumio volumio[2234]: info: [1713091350358] ControllerTidal::clearAddPlayTrack
Apr 14 12:42:30 volumio volumio[2234]: info: Getting stream with soundQuality LOSSLESS
Apr 14 12:42:30 volumio volumio[2234]: verbose: ControllerMpd::sendMpdCommand stop
Apr 14 12:42:30 volumio volumio[2234]: info: CoreStateMachine::updateTrackBlock
Apr 14 12:42:30 volumio volumio[2234]: info: CorePlayQueue::getTrackBlock
Apr 14 12:42:30 volumio volumio[2234]: info: sendMpdCommand status took 15 milliseconds
Apr 14 12:42:30 volumio volumio[2234]: info: sendMpdCommand stop took 6 milliseconds
Apr 14 12:42:30 volumio volumio[2234]: verbose: ControllerMpd::parseState
Apr 14 12:42:30 volumio volumio[2234]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 14 12:42:30 volumio volumio[2234]: verbose: ControllerMpd::sendMpdCommand clear
Apr 14 12:42:30 volumio volumio[2234]: info:
Apr 14 12:42:30 volumio volumio[2234]: ---------------------------- MPD announces system playlist update
Apr 14 12:42:30 volumio volumio[2234]: info: Ignoring MPD Status Update
Apr 14 12:42:30 volumio volumio[2234]: info: sendMpdCommand playlistinfo took 10 milliseconds
Apr 14 12:42:30 volumio volumio[2234]: info: sendMpdCommand clear took 10 milliseconds
Apr 14 12:42:30 volumio volumio[2234]: verbose: ControllerMpd::parseTrackInfo
Apr 14 12:42:30 volumio volumio[2234]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/5267737&soundQuality=LOSSLESS"
Apr 14 12:42:30 volumio volumio[2234]: info: ControllerMpd::pushState
Apr 14 12:42:30 volumio volumio[2234]: info: CoreCommandRouter::servicePushState
Apr 14 12:42:30 volumio volumio[2234]: info: CoreStateMachine::pushState
Apr 14 12:42:30 volumio volumio[2234]: info: CorePlayQueue::getTrack 1
Apr 14 12:42:30 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 14 12:42:30 volumio volumio[2234]: info: CoreCommandRouter::volumioPushState
Apr 14 12:42:30 volumio volumio[2234]: info: CorePlayQueue::getTrack 1
Apr 14 12:42:30 volumio volumio[2234]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd
Apr 14 12:42:30 volumio volumio[2234]: info: ------------------------------ 75ms
Apr 14 12:42:30 volumio volumio[2234]: error: updateQueue error: null
Apr 14 12:42:30 volumio volumio[2234]: info:
Apr 14 12:42:30 volumio volumio[2234]: ---------------------------- MPD announces system playlist update
Apr 14 12:42:30 volumio volumio[2234]: info: Ignoring MPD Status Update
Apr 14 12:42:30 volumio volumio[2234]: info: ------------------------------ 52ms
Apr 14 12:42:30 volumio volumio[2234]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/5267737&soundQuality=LOSSLESS" took 42 milliseconds
Apr 14 12:42:30 volumio volumio[2234]: info: CoreStateMachine::setConsumeUpdateService mpd
Apr 14 12:42:30 volumio volumio[2234]: verbose: ControllerMpd::sendMpdCommand play
Apr 14 12:42:30 volumio volumio[2234]: STREAMING PROXY: Handling url /?data=tidal://song/5267737&soundQuality=LOSSLESS
Apr 14 12:42:30 volumio volumio[2234]: info: ------------------------------ 33ms
Apr 14 12:42:30 volumio volumio[2234]: info: sendMpdCommand play took 29 milliseconds
Apr 14 12:42:30 volumio volumio[2234]: info: Executing endpoint getStreamUrltidal
Apr 14 12:42:30 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI
Apr 14 12:42:31 volumio volumio[2234]: info: getStreamUrl took 802 milliseconds
Apr 14 12:42:31 volumio volumio[2234]: STREAMING PROXY: Got real url: http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKRInNDUyZWRiNDFlMGUyZjdhMjY4NDc5Y2JiNzc1YjRjNGVfNjEubXA0/0.flac?token=1713094939~NjU3MjZjZWQ2OTI4ODk2NzU0OTZmMGY0ZmYzNTFlZTNkNzFlMmNkNw==
Apr 14 12:42:31 volumio volumio[2234]: STREAMING PROXY: Response: 200, length: 29314692
Apr 14 12:42:31 volumio volumio[2234]: info:
Apr 14 12:42:31 volumio volumio[2234]: ---------------------------- MPD announces state update: player
Apr 14 12:42:31 volumio volumio[2234]: info: ControllerMpd::getState
Apr 14 12:42:31 volumio volumio[2234]: verbose: ControllerMpd::sendMpdCommand status
Apr 14 12:42:31 volumio volumio[2234]: info:
Apr 14 12:42:31 volumio volumio[2234]: ---------------------------- MPD announces state update: player
Apr 14 12:42:31 volumio volumio[2234]: info: sendMpdCommand status took 5 milliseconds
Apr 14 12:42:31 volumio volumio[2234]: info: ControllerMpd::getState
Apr 14 12:42:31 volumio volumio[2234]: verbose: ControllerMpd::sendMpdCommand status
Apr 14 12:42:31 volumio volumio[2234]: verbose: ControllerMpd::parseState
Apr 14 12:42:31 volumio volumio[2234]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 14 12:42:31 volumio volumio[2234]: info: sendMpdCommand status took 6 milliseconds
Apr 14 12:42:31 volumio volumio[2234]: info: sendMpdCommand playlistinfo took 5 milliseconds
Apr 14 12:42:31 volumio volumio[2234]: verbose: ControllerMpd::parseState
Apr 14 12:42:31 volumio volumio[2234]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 14 12:42:31 volumio volumio[2234]: verbose: ControllerMpd::parseTrackInfo
Apr 14 12:42:31 volumio volumio[2234]: info: ControllerMpd::pushState
Apr 14 12:42:31 volumio volumio[2234]: info: CoreCommandRouter::servicePushState
Apr 14 12:42:31 volumio volumio[2234]: info: CorePlayQueue::getTrack 1
Apr 14 12:42:31 volumio volumio[2234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":243,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"5267737&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/5267737&soundQuality=LOSSLESS","trackType":"tidal"}
Apr 14 12:42:31 volumio volumio[2234]: verbose: CURRENT POSITION 1
Apr 14 12:42:31 volumio volumio[2234]: info: CoreStateMachine::syncState stateService play
Apr 14 12:42:31 volumio volumio[2234]: info: CoreStateMachine::syncState currentStatus stop
Apr 14 12:42:31 volumio volumio[2234]: info: ------------------------------ 32ms
Apr 14 12:42:31 volumio volumio[2234]: info: sendMpdCommand playlistinfo took 12 milliseconds
Apr 14 12:42:31 volumio volumio[2234]: verbose: ControllerMpd::parseTrackInfo
Apr 14 12:42:31 volumio volumio[2234]: info: ControllerMpd::pushState
Apr 14 12:42:31 volumio volumio[2234]: info: CoreCommandRouter::servicePushState
Apr 14 12:42:31 volumio volumio[2234]: info: CorePlayQueue::getTrack 1
Apr 14 12:42:31 volumio volumio[2234]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":243,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"5267737&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/5267737&soundQuality=LOSSLESS","trackType":"tidal"}
Apr 14 12:42:31 volumio volumio[2234]: verbose: CURRENT POSITION 1
Apr 14 12:42:31 volumio volumio[2234]: info: CoreStateMachine::syncState stateService play
Apr 14 12:42:31 volumio volumio[2234]: info: CoreStateMachine::syncState currentStatus play
Apr 14 12:42:31 volumio volumio[2234]: info: Received an update from plugin. extracting info from payload
Apr 14 12:42:31 volumio volumio[2234]: info: CoreStateMachine::pushState
Apr 14 12:42:31 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 14 12:42:31 volumio volumio[2234]: info: CoreCommandRouter::volumioPushState
Apr 14 12:42:31 volumio volumio[2234]: info: CoreStateMachine::pushState
Apr 14 12:42:31 volumio volumio[2234]: info: CoreCommandRouter::volumioPushState
Apr 14 12:42:31 volumio volumio[2234]: info: ------------------------------ 131ms
Apr 14 12:42:31 volumio volumio[2234]: info: [LastFM] Current track has sufficient metadata: title (Set Fire to the Rain) and artist (Adele) passed on explicitly
Apr 14 12:42:31 volumio volumio[2234]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"Set Fire to the Rain","mbid":"d1e0a99e-1894-457b-ba6a-985eeef4d0c4","url":"https://www.last.fm/music/Adele/_/Set+Fire+to+the+Rain","duration":"241000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"1541583","playcount":"15679210","artist":{"name":"Adele","mbid":"cc2c9c3c-b7bc-4b8b-84d8-4fbd8779e493","url":"https://www.last.fm/music/Adele"},"album":{"@":{"position":"5"},"artist":"Adele","title":"21","mbid":"c45e0e0e-48c9-4441-aac3-2f2b34202d3c","url":"https://www.last.fm/music/Adele/21","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/75075bd01c96465e54fc250b22f83296.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/75075bd01c96465e54fc250b22f83296.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/75075bd01c96465e54fc250b22f83296.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/75075bd01c96465e54fc250b22f83296.png","@":{"size":"extralarge"}}]},"userplaycount":"8","userloved":"0","toptags":{"tag":[{"name":"soul","url":"https://www.last.fm/tag/soul"},{"name":"Adele","url":"https://www.last.fm/tag/Adele"},{"name":"female vocalists","url":"https://www.last.fm/tag/female+vocalists"},{"name":"pop","url":"https://www.last.fm/tag/pop"},{"name":"british","url":"https://www.last.fm/tag/british"}]},"wiki":{"published":"13 Aug 2011, 15:46","summary":"\"Set Fire to the Rain\" is a song performed by english singer-songwriter Adele, released as the third single from her studio album, 21. The song talks about a relationship coming to an end. Girl meets guy, he is wonderful and she falls really quickly. He tells her all of these amazing things, but really they were all a lie and now she is left with a broken heart. He continually tries to play games with her and no matter hard she fights, she will never win. Nothing she can do will fix the relationship. Read more on Last.fm.","content":"\"Set Fire to the Rain\" is a song performed by english singer-songwriter Adele, released as the third single from her studio album, 21. The song talks about a relationship coming to an end. Girl meets guy, he is wonderful and she falls really quickly. He tells her all of these amazing things, but really they were all a lie and now she is left with a broken heart. He continually tries to play games with her and no matter hard she fights, she will never win. Nothing she can do will fix the relationship. As hard as she doesn’t want to let him go, she breaks it off in order to save herself for further heartbreak. The pain of breaking off a relationship with someone who means so much but is two-sided and not good to be with. The title is an allusion to James Taylor’s Fire and Rain, but Adele approaches the same themes with a thug-feminist perspective. In the US, the song hit #1, becoming her third consecutive number one from the album. She wouldn’t reach such heights again until her comeback single Hello debuted at number one with a shocking 1.12 million copies sold in one week – the largest ever recorded in the US. Read more on Last.fm. User-contributed text is available under the Creative Commons By-SA License; additional terms may apply."}}}
Apr 14 12:42:32 volumio volumio[2234]: error: Failed request for metavolumio API
Apr 14 12:42:32 volumio volumio[2234]: info: Executing endpoint metavolumio
Apr 14 12:42:32 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 14 12:42:32 volumio volumio[2234]: STREAMING PROXY: Client dropped request, destroying
Apr 14 12:42:32 volumio volumio[2234]: info: Executing endpoint metavolumio
Apr 14 12:42:32 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 14 12:42:32 volumio volumio[2234]: info: Executing endpoint metavolumio
Apr 14 12:42:32 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 14 12:42:35 volumio kernel: perf: interrupt took too long (5119 > 5101), lowering kernel.perf_event_max_sample_rate to 39000
Apr 14 12:42:39 volumio volumio[2234]: error: Failed request for metavolumio API
Apr 14 12:42:41 volumio volumio[2234]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 14 12:42:41 volumio volumio[2234]: /bin/cat: /sys/class/net/wlan0/flags: No such file or directory
Apr 14 12:42:41 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus
Apr 14 12:42:41 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork
Apr 14 12:42:41 volumio sudo[2810]: volumio : unable to resolve host volumio
Apr 14 12:42:41 volumio sudo[2810]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
Apr 14 12:42:42 volumio sudo[2810]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0
Apr 14 12:42:42 volumio sudo[2810]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 14 12:42:42 volumio sudo[2810]: pam_unix(sudo:session): session closed for user root
Apr 14 12:42:42 volumio sudo[2815]: volumio : unable to resolve host volumio
Apr 14 12:42:42 volumio sudo[2815]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
Apr 14 12:42:42 volumio sudo[2815]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0
Apr 14 12:42:42 volumio sudo[2815]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 14 12:42:42 volumio sudo[2823]: volumio : unable to resolve host volumio
Apr 14 12:42:42 volumio sudo[2823]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
Apr 14 12:42:42 volumio sudo[2823]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0
Apr 14 12:42:42 volumio sudo[2823]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 14 12:42:42 volumio sudo[2815]: pam_unix(sudo:session): session closed for user root
Apr 14 12:42:42 volumio sudo[2830]: volumio : unable to resolve host volumio
Apr 14 12:42:42 volumio sudo[2830]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
Apr 14 12:42:42 volumio sudo[2830]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0
Apr 14 12:42:42 volumio sudo[2830]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 14 12:42:42 volumio sudo[2823]: pam_unix(sudo:session): session closed for user root
Apr 14 12:42:42 volumio sudo[2842]: volumio : unable to resolve host volumio
Apr 14 12:42:42 volumio sudo[2842]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
Apr 14 12:42:42 volumio sudo[2842]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Apr 14 12:42:42 volumio sudo[2842]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 14 12:42:42 volumio sudo[2842]: pam_unix(sudo:session): session closed for user root
Apr 14 12:42:42 volumio sudo[2848]: volumio : unable to resolve host volumio
Apr 14 12:42:42 volumio sudo[2848]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
Apr 14 12:42:42 volumio sudo[2830]: pam_unix(sudo:session): session closed for user root
Apr 14 12:42:42 volumio sudo[2848]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Apr 14 12:42:42 volumio sudo[2848]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 14 12:42:42 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache
Apr 14 12:42:42 volumio sudo[2848]: pam_unix(sudo:session): session closed for user root
Apr 14 12:42:42 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks
Apr 14 12:42:42 volumio sudo[2856]: volumio : unable to resolve host volumio
Apr 14 12:42:42 volumio sudo[2856]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
Apr 14 12:42:42 volumio sudo[2856]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Apr 14 12:42:42 volumio sudo[2856]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 14 12:42:42 volumio sudo[2856]: pam_unix(sudo:session): session closed for user root
Apr 14 12:42:42 volumio volumio[2234]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan
Apr 14 12:42:42 volumio volumio[2234]: sudo: unable to resolve host volumio: System error
Apr 14 12:42:42 volumio volumio[2234]: wlan0 Interface doesn't support scanning.
Apr 14 12:42:42 volumio volumio[2234]: info: Cannot use regular scanning, forcing with ap-force
Apr 14 12:42:42 volumio sudo[2861]: volumio : unable to resolve host volumio
Apr 14 12:42:42 volumio sudo[2861]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
Apr 14 12:42:42 volumio sudo[2861]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force
Apr 14 12:42:42 volumio sudo[2861]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 14 12:42:42 volumio sudo[2861]: pam_unix(sudo:session): session closed for user root
Apr 14 12:42:42 volumio volumio[2234]: sudo: unable to resolve host volumio: System error
Apr 14 12:42:42 volumio volumio[2234]: command failed: No such device (-19)
Apr 14 12:42:42 volumio volumio[2234]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force
Apr 14 12:42:42 volumio volumio[2234]: sudo: unable to resolve host volumio: System error
Apr 14 12:42:42 volumio volumio[2234]: command failed: No such device (-19)
Apr 14 12:42:53 volumio volumio[2234]: info: CoreCommandRouter::volumioGetState
Apr 14 12:42:54 volumio volumio[2234]: info: CoreCommandRouter::volumioGetQueue
Apr 14 12:42:54 volumio volumio[2234]: info: CoreStateMachine::getQueue
Apr 14 12:42:54 volumio volumio[2234]: info: CorePlayQueue::getQueue
Apr 14 12:42:55 volumio volumio[2234]: info: Executing endpoint metavolumio
Apr 14 12:42:55 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 14 12:42:55 volumio volumio[2234]: info: Executing endpoint metavolumio
Apr 14 12:42:55 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 14 12:42:55 volumio volumio[2234]: info: Executing endpoint metavolumio
Apr 14 12:42:55 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 14 12:43:00 volumio ntpd[747]: 193.25.222.136 local addr 192.168.1.91 ->
Apr 14 12:43:04 volumio volumio[2234]: info: CoreCommandRouter::volumioGetState
Apr 14 12:43:06 volumio volumio[2234]: info: Executing endpoint metavolumio
Apr 14 12:43:06 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 14 12:43:06 volumio volumio[2234]: info: Executing endpoint metavolumio
Apr 14 12:43:06 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 14 12:43:06 volumio volumio[2234]: info: Executing endpoint metavolumio
Apr 14 12:43:06 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 14 12:43:09 volumio ntpd[747]: 162.159.200.1 local addr 192.168.1.91 ->
Apr 14 12:43:11 volumio volumio[2234]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 14 12:43:11 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions
Apr 14 12:43:11 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 14 12:43:11 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Apr 14 12:43:11 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 14 12:43:11 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 14 12:43:11 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 14 12:43:11 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 14 12:43:11 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 14 12:43:11 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 14 12:43:11 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 14 12:43:11 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode
Apr 14 12:43:11 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus
Apr 14 12:43:22 volumio volumio[2234]: info: CoreCommandRouter::volumioGetState
Apr 14 12:43:24 volumio volumio[2234]: info: Executing endpoint metavolumio
Apr 14 12:43:24 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 14 12:43:24 volumio volumio[2234]: info: Executing endpoint metavolumio
Apr 14 12:43:24 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 14 12:43:24 volumio volumio[2234]: info: Executing endpoint metavolumio
Apr 14 12:43:24 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 14 12:43:30 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Apr 14 12:43:30 volumio volumio[2234]: info: Preload queue cleared
Apr 14 12:43:33 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Apr 14 12:43:34 volumio volumio[2234]: info: Preload queue cleared
Apr 14 12:43:36 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Apr 14 12:43:36 volumio volumio[2234]: info: Preload queue cleared
Apr 14 12:43:38 volumio volumio[2234]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Apr 14 12:43:38 volumio volumio[2234]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 14 12:43:38 volumio volumio[2234]: TypeError: Cannot read property 'length' of undefined
Apr 14 12:43:38 volumio volumio[2234]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25
Apr 14 12:43:38 volumio volumio[2234]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13
Apr 14 12:43:38 volumio volumio[2234]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18)
Apr 14 12:43:38 volumio volumio[2234]: at Parser.emit (events.js:400:28)
Apr 14 12:43:38 volumio volumio[2234]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26)
Apr 14 12:43:38 volumio volumio[2234]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35)
Apr 14 12:43:38 volumio volumio[2234]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5)
Apr 14 12:43:38 volumio volumio[2234]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7)
Apr 14 12:43:38 volumio volumio[2234]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13)
Apr 14 12:43:38 volumio volumio[2234]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31)
Apr 14 12:43:38 volumio volumio[2234]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59)
Apr 14 12:43:38 volumio volumio[2234]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19)
Apr 14 12:43:38 volumio volumio[2234]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15)
Apr 14 12:43:38 volumio volumio[2234]: at IncomingMessage.emit (events.js:412:35)
Apr 14 12:43:38 volumio volumio[2234]: at endReadableNT (internal/streams/readable.js:1333:12)
Apr 14 12:43:38 volumio volumio[2234]: at processTicksAndRejections (internal/process/task_queues.js:82:21)
Apr 14 12:43:38 volumio volumio[2234]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 14 12:43:39 volumio sudo[2919]: volumio : unable to resolve host volumio
Apr 14 12:43:39 volumio sudo[2919]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ;
Apr 14 12:43:39 volumio sudo[2919]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-14 12:42
Apr 14 12:43:39 volumio sudo[2919]: 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="7b9cb4a8b52fb7148a38d6ac651c1c29e09bb92c"
VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71"
VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1"
VOLUMIO_BE_VERSION="b1dcc17f6d31bf91f0abd3c3fa57506d1e0d2b6b"
VOLUMIO_ARCH="x64"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Fri 01 Mar 2024 08:52:33 PM CET"
VOLUMIO_VERSION="3.634"
VOLUMIO_HARDWARE="x86_amd64"
VOLUMIO_DEVICENAME="x86_64"
VOLUMIO_HASH="93edfc70711724967af109c0a39fa069"