-- Logs begin at Thu 2019-02-14 15:11:59 +05, end at Sat 2025-12-27 06:00:09 +05. -- Dec 27 05:59:05 zero volumio[819]: info: BOOT COMPLETED Dec 27 05:59:06 zero ntpd[667]: Soliciting pool server 79.111.119.96 Dec 27 05:59:07 zero ntpd[667]: Soliciting pool server 51.250.53.172 Dec 27 05:59:07 zero ntpd[667]: Soliciting pool server 85.21.78.91 Dec 27 05:59:08 zero ntpd[667]: Soliciting pool server 90.188.9.144 Dec 27 05:59:08 zero ntpd[667]: Soliciting pool server 89.109.251.28 Dec 27 05:59:09 zero ntpd[667]: Soliciting pool server 89.188.118.150 Dec 27 05:59:09 zero ntpd[667]: Soliciting pool server 89.109.251.23 Dec 27 05:59:09 zero ntpd[667]: Soliciting pool server 92.255.126.3 Dec 27 05:59:09 zero ntpd[667]: Soliciting pool server 185.188.183.188 Dec 27 05:59:10 zero volumio[1058]: ..............................................................................................................................................................................................................++++ Dec 27 05:59:10 zero volumio[1058]: e is 65537 (0x010001) Dec 27 05:59:10 zero ntpd[667]: Soliciting pool server 51.250.68.198 Dec 27 05:59:10 zero ntpd[667]: Soliciting pool server 188.225.9.167 Dec 27 05:59:10 zero ntpd[667]: Soliciting pool server 109.195.84.246 Dec 27 05:59:10 zero volumio[1058]: writing RSA key Dec 27 05:59:11 zero ntpd[667]: Soliciting pool server 93.191.12.44 Dec 27 05:59:11 zero ntpd[667]: Soliciting pool server 91.244.115.121 Dec 27 05:59:11 zero ntpd[667]: Soliciting pool server 193.192.36.120 Dec 27 05:59:12 zero ntpd[667]: Soliciting pool server 46.188.16.150 Dec 27 05:59:12 zero ntpd[667]: Soliciting pool server 46.138.254.88 Dec 27 05:59:12 zero ntpd[667]: Soliciting pool server 195.122.253.38 Dec 27 05:59:16 zero ntpd[667]: receive: Unexpected origin timestamp 0xecf9ade4.19be4035 does not match aorg 0000000000.00000000 from server@51.250.68.198 xmt 0xecf9ade4.9df2091c Dec 27 05:59:16 zero ntpd[667]: receive: Unexpected origin timestamp 0xecf9ade4.19c4e688 does not match aorg 0000000000.00000000 from server@85.21.78.91 xmt 0xecf9ade4.9e3b5160 Dec 27 05:59:16 zero ntpd[667]: receive: Unexpected origin timestamp 0xecf9ade4.19c2372b does not match aorg 0000000000.00000000 from server@90.188.9.144 xmt 0xecf9ade4.9dd7bef6 Dec 27 05:59:16 zero ntpd[667]: receive: Unexpected origin timestamp 0xecf9ade4.19bf93c1 does not match aorg 0000000000.00000000 from server@185.188.183.188 xmt 0xecf9ade4.9dc3750c Dec 27 05:59:16 zero ntpd[667]: receive: Unexpected origin timestamp 0xecf9ade4.19c39900 does not match aorg 0000000000.00000000 from server@51.250.53.172 xmt 0xecf9ade4.9e2af46b Dec 27 05:59:16 zero ntpd[667]: receive: Unexpected origin timestamp 0xecf9ade4.19bce190 does not match aorg 0000000000.00000000 from server@188.225.9.167 xmt 0xecf9ade4.9ebe930c Dec 27 05:59:16 zero ntpd[667]: receive: Unexpected origin timestamp 0xecf9ade4.19bb5148 does not match aorg 0000000000.00000000 from server@193.192.36.120 xmt 0xecf9ade4.a19cae5e Dec 27 05:59:16 zero ntpd[667]: receive: Unexpected origin timestamp 0xecf9ade4.19b77597 does not match aorg 0000000000.00000000 from server@91.244.115.121 xmt 0xecf9ade4.9ded4a1a Dec 27 05:59:49 zero volumio[819]: info: CoreCommandRouter::volumioGetState Dec 27 05:59:49 zero volumio[819]: info: CorePlayQueue::getTrack 0 Dec 27 05:59:51 zero volumio[819]: info: CoreCommandRouter::volumioPlay Dec 27 05:59:51 zero volumio[819]: info: CoreStateMachine::play index undefined Dec 27 05:59:51 zero volumio[819]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 27 05:59:51 zero volumio[819]: info: CorePlayQueue::getTrack 0 Dec 27 05:59:51 zero volumio[819]: info: CoreStateMachine::startPlaybackTimer Dec 27 05:59:51 zero volumio[819]: info: CorePlayQueue::getTrack 0 Dec 27 05:59:51 zero volumio[819]: info: [1766797191240] ControllerWebradio::clearAddPlayTrack Dec 27 05:59:51 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand stop Dec 27 05:59:51 zero volumio[819]: info: sendMpdCommand stop took 3 milliseconds Dec 27 05:59:51 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand clear Dec 27 05:59:51 zero volumio[819]: info: Dec 27 05:59:51 zero volumio[819]: ---------------------------- MPD announces system playlist update Dec 27 05:59:51 zero volumio[819]: info: Ignoring MPD Status Update Dec 27 05:59:51 zero volumio[819]: info: sendMpdCommand clear took 5 milliseconds Dec 27 05:59:51 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand load "http://stream.radioparadise.com/mellow-flac" Dec 27 05:59:51 zero volumio[819]: info: Dec 27 05:59:51 zero volumio[819]: ---------------------------- MPD announces system playlist update Dec 27 05:59:51 zero volumio[819]: info: Ignoring MPD Status Update Dec 27 05:59:51 zero volumio[819]: info: Dec 27 05:59:51 zero volumio[819]: ---------------------------- MPD announces system playlist update Dec 27 05:59:51 zero volumio[819]: info: Ignoring MPD Status Update Dec 27 05:59:51 zero volumio[819]: error: updateQueue error: null Dec 27 05:59:51 zero volumio[819]: info: ------------------------------ 14ms Dec 27 05:59:51 zero volumio[819]: error: Upnp client error: Error: This socket has been ended by the other party Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand add "http://stream.radioparadise.com/mellow-flac" Dec 27 05:59:52 zero volumio[819]: error: updateQueue error: null Dec 27 05:59:52 zero volumio[819]: error: updateQueue error: null Dec 27 05:59:52 zero volumio[819]: info: Dec 27 05:59:52 zero volumio[819]: ---------------------------- MPD announces system playlist update Dec 27 05:59:52 zero volumio[819]: info: Ignoring MPD Status Update Dec 27 05:59:52 zero volumio[819]: info: ------------------------------ 817ms Dec 27 05:59:52 zero volumio[819]: info: ------------------------------ 814ms Dec 27 05:59:52 zero volumio[819]: info: sendMpdCommand add "http://stream.radioparadise.com/mellow-flac" took 5 milliseconds Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand play Dec 27 05:59:52 zero volumio[819]: info: Dec 27 05:59:52 zero volumio[819]: ---------------------------- MPD announces system playlist update Dec 27 05:59:52 zero volumio[819]: info: Ignoring MPD Status Update Dec 27 05:59:52 zero volumio[819]: info: Dec 27 05:59:52 zero volumio[819]: ---------------------------- MPD announces system playlist update Dec 27 05:59:52 zero volumio[819]: info: Ignoring MPD Status Update Dec 27 05:59:52 zero volumio[819]: info: ------------------------------ 11ms Dec 27 05:59:52 zero volumio[819]: info: sendMpdCommand play took 8 milliseconds Dec 27 05:59:52 zero volumio[819]: info: ------------------------------ 7ms Dec 27 05:59:52 zero volumio[819]: info: ------------------------------ 6ms Dec 27 05:59:52 zero volumio[819]: info: Dec 27 05:59:52 zero volumio[819]: ---------------------------- MPD announces state update: player Dec 27 05:59:52 zero volumio[819]: info: ControllerMpd::getState Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand status Dec 27 05:59:52 zero volumio[819]: info: Dec 27 05:59:52 zero volumio[819]: ---------------------------- MPD announces state update: player Dec 27 05:59:52 zero volumio[819]: info: ControllerMpd::getState Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand status Dec 27 05:59:52 zero volumio[819]: info: Dec 27 05:59:52 zero volumio[819]: ---------------------------- MPD announces state update: player Dec 27 05:59:52 zero volumio[819]: info: ControllerMpd::getState Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand status Dec 27 05:59:52 zero volumio[819]: info: Dec 27 05:59:52 zero volumio[819]: ---------------------------- MPD announces state update: player Dec 27 05:59:52 zero volumio[819]: info: sendMpdCommand status took 11 milliseconds Dec 27 05:59:52 zero volumio[819]: info: ControllerMpd::getState Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand status Dec 27 05:59:52 zero volumio[819]: info: sendMpdCommand status took 9 milliseconds Dec 27 05:59:52 zero volumio[819]: info: sendMpdCommand status took 6 milliseconds Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::parseState Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::parseState Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::parseState Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 05:59:52 zero volumio[819]: info: Dec 27 05:59:52 zero volumio[819]: ---------------------------- MPD announces state update: player Dec 27 05:59:52 zero volumio[819]: info: ControllerMpd::getState Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand status Dec 27 05:59:52 zero volumio[819]: info: Dec 27 05:59:52 zero volumio[819]: ---------------------------- MPD announces state update: player Dec 27 05:59:52 zero volumio[819]: info: ControllerMpd::getState Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand status Dec 27 05:59:52 zero volumio[819]: info: sendMpdCommand status took 15 milliseconds Dec 27 05:59:52 zero volumio[819]: info: sendMpdCommand playlistinfo took 11 milliseconds Dec 27 05:59:52 zero volumio[819]: info: sendMpdCommand playlistinfo took 10 milliseconds Dec 27 05:59:52 zero volumio[819]: info: sendMpdCommand playlistinfo took 10 milliseconds Dec 27 05:59:52 zero volumio[819]: info: sendMpdCommand status took 7 milliseconds Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::parseState Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::parseTrackInfo Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::parseTrackInfo Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::parseTrackInfo Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::parseState Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 05:59:52 zero volumio[819]: info: ControllerMpd::pushState Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::servicePushState Dec 27 05:59:52 zero volumio[819]: info: CorePlayQueue::getTrack 0 Dec 27 05:59:52 zero volumio[819]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"mellow-flac","artist":null,"album":null,"uri":"http://stream.radioparadise.com/mellow-flac","trackType":""} Dec 27 05:59:52 zero volumio[819]: verbose: CURRENT POSITION 0 Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::syncState stateService play Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::syncState currentStatus stop Dec 27 05:59:52 zero volumio[819]: info: ControllerMpd::pushState Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::servicePushState Dec 27 05:59:52 zero volumio[819]: info: CorePlayQueue::getTrack 0 Dec 27 05:59:52 zero volumio[819]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"mellow-flac","artist":null,"album":null,"uri":"http://stream.radioparadise.com/mellow-flac","trackType":""} Dec 27 05:59:52 zero volumio[819]: verbose: CURRENT POSITION 0 Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::syncState stateService play Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::syncState currentStatus play Dec 27 05:59:52 zero volumio[819]: info: Received an update from plugin. extracting info from payload Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::pushState Dec 27 05:59:52 zero volumio[819]: info: CorePlayQueue::getTrack 0 Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::volumioPushState Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::pushState Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::volumioPushState Dec 27 05:59:52 zero volumio[819]: info: ControllerMpd::pushState Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::servicePushState Dec 27 05:59:52 zero volumio[819]: info: CorePlayQueue::getTrack 0 Dec 27 05:59:52 zero volumio[819]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"mellow-flac","artist":null,"album":null,"uri":"http://stream.radioparadise.com/mellow-flac","trackType":""} Dec 27 05:59:52 zero volumio[819]: verbose: CURRENT POSITION 0 Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::syncState stateService play Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::syncState currentStatus play Dec 27 05:59:52 zero volumio[819]: info: Received an update from plugin. extracting info from payload Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::pushState Dec 27 05:59:52 zero volumio[819]: info: CorePlayQueue::getTrack 0 Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::volumioPushState Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::pushState Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::volumioPushState Dec 27 05:59:52 zero volumio[819]: info: ------------------------------ 87ms Dec 27 05:59:52 zero volumio[819]: info: ------------------------------ 121ms Dec 27 05:59:52 zero volumio[819]: info: ------------------------------ 119ms Dec 27 05:59:52 zero volumio[819]: info: Dec 27 05:59:52 zero volumio[819]: ---------------------------- MPD announces system playlist update Dec 27 05:59:52 zero volumio[819]: info: Ignoring MPD Status Update Dec 27 05:59:52 zero volumio[819]: info: Dec 27 05:59:52 zero volumio[819]: ---------------------------- MPD announces state update: player Dec 27 05:59:52 zero volumio[819]: info: ControllerMpd::getState Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand status Dec 27 05:59:52 zero volumio[819]: info: Dec 27 05:59:52 zero volumio[819]: ---------------------------- MPD announces system playlist update Dec 27 05:59:52 zero volumio[819]: info: Ignoring MPD Status Update Dec 27 05:59:52 zero volumio[819]: info: Dec 27 05:59:52 zero volumio[819]: ---------------------------- MPD announces state update: player Dec 27 05:59:52 zero volumio[819]: info: sendMpdCommand status took 108 milliseconds Dec 27 05:59:52 zero volumio[819]: info: sendMpdCommand playlistinfo took 104 milliseconds Dec 27 05:59:52 zero volumio[819]: info: sendMpdCommand playlistinfo took 98 milliseconds Dec 27 05:59:52 zero volumio[819]: info: ControllerMpd::getState Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand status Dec 27 05:59:52 zero volumio[819]: info: ------------------------------ 10ms Dec 27 05:59:52 zero volumio[819]: info: sendMpdCommand status took 7 milliseconds Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::parseState Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::parseTrackInfo Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::parseTrackInfo Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::parseState Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 05:59:52 zero volumio[819]: info: ControllerMpd::pushState Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::servicePushState Dec 27 05:59:52 zero volumio[819]: info: CorePlayQueue::getTrack 0 Dec 27 05:59:52 zero volumio[819]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"mellow-flac","artist":null,"album":null,"uri":"http://stream.radioparadise.com/mellow-flac","trackType":""} Dec 27 05:59:52 zero volumio[819]: verbose: CURRENT POSITION 0 Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::syncState stateService play Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::syncState currentStatus play Dec 27 05:59:52 zero volumio[819]: info: Received an update from plugin. extracting info from payload Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::pushState Dec 27 05:59:52 zero volumio[819]: info: CorePlayQueue::getTrack 0 Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::volumioPushState Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::pushState Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::volumioPushState Dec 27 05:59:52 zero volumio[819]: info: ControllerMpd::pushState Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::servicePushState Dec 27 05:59:52 zero volumio[819]: info: CorePlayQueue::getTrack 0 Dec 27 05:59:52 zero volumio[819]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"mellow-flac","artist":null,"album":null,"uri":"http://stream.radioparadise.com/mellow-flac","trackType":""} Dec 27 05:59:52 zero volumio[819]: verbose: CURRENT POSITION 0 Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::syncState stateService play Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::syncState currentStatus play Dec 27 05:59:52 zero volumio[819]: info: Received an update from plugin. extracting info from payload Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::pushState Dec 27 05:59:52 zero volumio[819]: info: CorePlayQueue::getTrack 0 Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::volumioPushState Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::pushState Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::volumioPushState Dec 27 05:59:52 zero volumio[819]: info: ------------------------------ 203ms Dec 27 05:59:52 zero volumio[819]: info: ------------------------------ 193ms Dec 27 05:59:52 zero volumio[819]: info: Dec 27 05:59:52 zero volumio[819]: ---------------------------- MPD announces system playlist update Dec 27 05:59:52 zero volumio[819]: info: Ignoring MPD Status Update Dec 27 05:59:52 zero volumio[819]: info: Dec 27 05:59:52 zero volumio[819]: ---------------------------- MPD announces state update: player Dec 27 05:59:52 zero volumio[819]: info: ControllerMpd::getState Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand status Dec 27 05:59:52 zero volumio[819]: info: ------------------------------ 115ms Dec 27 05:59:52 zero volumio[819]: info: sendMpdCommand status took 111 milliseconds Dec 27 05:59:52 zero volumio[819]: info: sendMpdCommand playlistinfo took 110 milliseconds Dec 27 05:59:52 zero volumio[819]: info: sendMpdCommand playlistinfo took 107 milliseconds Dec 27 05:59:52 zero volumio[819]: info: ------------------------------ 16ms Dec 27 05:59:52 zero volumio[819]: info: sendMpdCommand status took 14 milliseconds Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::parseState Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::parseTrackInfo Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::parseTrackInfo Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::parseState Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 05:59:52 zero volumio[819]: info: ControllerMpd::pushState Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::servicePushState Dec 27 05:59:52 zero volumio[819]: info: CorePlayQueue::getTrack 0 Dec 27 05:59:52 zero volumio[819]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"mellow-flac","artist":"Radio Paradise: Mellow Mix (flac) - playlist: radioparadise.com","album":null,"uri":"http://stream.radioparadise.com/mellow-flac","trackType":""} Dec 27 05:59:52 zero volumio[819]: verbose: CURRENT POSITION 0 Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::syncState stateService play Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::syncState currentStatus play Dec 27 05:59:52 zero volumio[819]: info: Received an update from plugin. extracting info from payload Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::pushState Dec 27 05:59:52 zero volumio[819]: info: CorePlayQueue::getTrack 0 Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::volumioPushState Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::pushState Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::volumioPushState Dec 27 05:59:52 zero volumio[819]: info: ControllerMpd::pushState Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::servicePushState Dec 27 05:59:52 zero volumio[819]: info: CorePlayQueue::getTrack 0 Dec 27 05:59:52 zero volumio[819]: verbose: STATE SERVICE {"status":"play","position":0,"seek":846,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"mellow-flac","artist":"Radio Paradise: Mellow Mix (flac) - playlist: radioparadise.com","album":null,"uri":"http://stream.radioparadise.com/mellow-flac","trackType":""} Dec 27 05:59:52 zero volumio[819]: verbose: CURRENT POSITION 0 Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::syncState stateService play Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::syncState currentStatus play Dec 27 05:59:52 zero volumio[819]: info: Received an update from plugin. extracting info from payload Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::pushState Dec 27 05:59:52 zero volumio[819]: info: CorePlayQueue::getTrack 0 Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::volumioPushState Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::pushState Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::volumioPushState Dec 27 05:59:52 zero volumio[819]: info: ------------------------------ 302ms Dec 27 05:59:52 zero volumio[819]: info: ------------------------------ 200ms Dec 27 05:59:52 zero volumio[819]: info: sendMpdCommand playlistinfo took 80 milliseconds Dec 27 05:59:52 zero volumio[819]: info: sendMpdCommand playlistinfo took 79 milliseconds Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::parseTrackInfo Dec 27 05:59:52 zero volumio[819]: verbose: ControllerMpd::parseTrackInfo Dec 27 05:59:52 zero volumio[819]: info: ControllerMpd::pushState Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::servicePushState Dec 27 05:59:52 zero volumio[819]: info: CorePlayQueue::getTrack 0 Dec 27 05:59:52 zero volumio[819]: verbose: STATE SERVICE {"status":"play","position":0,"seek":846,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"mellow-flac","artist":"Radio Paradise: Mellow Mix (flac) - playlist: radioparadise.com","album":null,"uri":"http://stream.radioparadise.com/mellow-flac","trackType":""} Dec 27 05:59:52 zero volumio[819]: verbose: CURRENT POSITION 0 Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::syncState stateService play Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::syncState currentStatus play Dec 27 05:59:52 zero volumio[819]: info: Received an update from plugin. extracting info from payload Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::pushState Dec 27 05:59:52 zero volumio[819]: info: CorePlayQueue::getTrack 0 Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::volumioPushState Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::pushState Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::volumioPushState Dec 27 05:59:52 zero volumio[819]: info: ControllerMpd::pushState Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::servicePushState Dec 27 05:59:52 zero volumio[819]: info: CorePlayQueue::getTrack 0 Dec 27 05:59:52 zero volumio[819]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1098,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"mellow-flac","artist":"Radio Paradise: Mellow Mix (flac) - playlist: radioparadise.com","album":null,"uri":"http://stream.radioparadise.com/mellow-flac","trackType":""} Dec 27 05:59:52 zero volumio[819]: verbose: CURRENT POSITION 0 Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::syncState stateService play Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::syncState currentStatus play Dec 27 05:59:52 zero volumio[819]: info: Received an update from plugin. extracting info from payload Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::pushState Dec 27 05:59:52 zero volumio[819]: info: CorePlayQueue::getTrack 0 Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::volumioPushState Dec 27 05:59:52 zero volumio[819]: info: CoreStateMachine::pushState Dec 27 05:59:52 zero volumio[819]: info: CoreCommandRouter::volumioPushState Dec 27 05:59:52 zero volumio[819]: info: ------------------------------ 272ms Dec 27 05:59:52 zero volumio[819]: info: ------------------------------ 172ms Dec 27 05:59:54 zero volumio[819]: info: CoreCommandRouter::volumioStop Dec 27 05:59:54 zero volumio[819]: info: CoreStateMachine::stop Dec 27 05:59:54 zero volumio[819]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 27 05:59:54 zero volumio[819]: info: CoreStateMachine::stPlaybackTimer Dec 27 05:59:54 zero volumio[819]: info: CoreStateMachine::updateTrackBlock Dec 27 05:59:54 zero volumio[819]: info: CorePlayQueue::getTrackBlock Dec 27 05:59:54 zero volumio[819]: info: CoreStateMachine::pushState Dec 27 05:59:54 zero volumio[819]: info: CorePlayQueue::getTrack 0 Dec 27 05:59:54 zero volumio[819]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 05:59:54 zero volumio[819]: info: CoreCommandRouter::volumioPushState Dec 27 05:59:54 zero volumio[819]: info: CoreStateMachine::serviceStop Dec 27 05:59:54 zero volumio[819]: info: CorePlayQueue::getTrack 0 Dec 27 05:59:54 zero volumio[819]: info: CoreCommandRouter::serviceStop Dec 27 05:59:54 zero volumio[819]: info: [1766797194148] ControllerWebradio::stop Dec 27 05:59:54 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand stop Dec 27 05:59:54 zero volumio[819]: info: Dec 27 05:59:54 zero volumio[819]: ---------------------------- MPD announces state update: player Dec 27 05:59:54 zero volumio[819]: info: sendMpdCommand stop took 13 milliseconds Dec 27 05:59:54 zero volumio[819]: info: ControllerMpd::getState Dec 27 05:59:54 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand status Dec 27 05:59:54 zero volumio[819]: info: sendMpdCommand status took 2 milliseconds Dec 27 05:59:54 zero volumio[819]: verbose: ControllerMpd::parseState Dec 27 05:59:54 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 05:59:54 zero volumio[819]: info: Dec 27 05:59:54 zero volumio[819]: ---------------------------- MPD announces state update: player Dec 27 05:59:54 zero volumio[819]: info: ControllerMpd::getState Dec 27 05:59:54 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand status Dec 27 05:59:54 zero volumio[819]: info: Dec 27 05:59:54 zero volumio[819]: ---------------------------- MPD announces state update: player Dec 27 05:59:54 zero volumio[819]: info: ControllerMpd::getState Dec 27 05:59:54 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand status Dec 27 05:59:54 zero volumio[819]: info: sendMpdCommand playlistinfo took 8 milliseconds Dec 27 05:59:54 zero volumio[819]: info: sendMpdCommand status took 6 milliseconds Dec 27 05:59:54 zero volumio[819]: info: sendMpdCommand status took 3 milliseconds Dec 27 05:59:54 zero volumio[819]: verbose: ControllerMpd::parseTrackInfo Dec 27 05:59:54 zero volumio[819]: verbose: ControllerMpd::parseState Dec 27 05:59:54 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 05:59:54 zero volumio[819]: verbose: ControllerMpd::parseState Dec 27 05:59:54 zero volumio[819]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 05:59:54 zero volumio[819]: info: ControllerMpd::pushState Dec 27 05:59:54 zero volumio[819]: info: CoreCommandRouter::servicePushState Dec 27 05:59:54 zero volumio[819]: info: CoreStateMachine::pushState Dec 27 05:59:54 zero volumio[819]: info: CorePlayQueue::getTrack 0 Dec 27 05:59:54 zero volumio[819]: info: CoreCommandRouter::volumioPushState Dec 27 05:59:54 zero volumio[819]: info: CorePlayQueue::getTrack 0 Dec 27 05:59:54 zero volumio[819]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Dec 27 05:59:54 zero volumio[819]: info: ------------------------------ 39ms Dec 27 05:59:54 zero volumio[819]: info: sendMpdCommand playlistinfo took 25 milliseconds Dec 27 05:59:54 zero volumio[819]: info: sendMpdCommand playlistinfo took 24 milliseconds Dec 27 05:59:54 zero volumio[819]: verbose: ControllerMpd::parseTrackInfo Dec 27 05:59:54 zero volumio[819]: verbose: ControllerMpd::parseTrackInfo Dec 27 05:59:54 zero volumio[819]: info: ControllerMpd::pushState Dec 27 05:59:54 zero volumio[819]: info: CoreCommandRouter::servicePushState Dec 27 05:59:54 zero volumio[819]: info: CoreStateMachine::pushState Dec 27 05:59:54 zero volumio[819]: info: CorePlayQueue::getTrack 0 Dec 27 05:59:54 zero volumio[819]: info: CoreCommandRouter::volumioPushState Dec 27 05:59:54 zero volumio[819]: info: CorePlayQueue::getTrack 0 Dec 27 05:59:54 zero volumio[819]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Dec 27 05:59:54 zero volumio[819]: info: ControllerMpd::pushState Dec 27 05:59:54 zero volumio[819]: info: CoreCommandRouter::servicePushState Dec 27 05:59:54 zero volumio[819]: info: CoreStateMachine::pushState Dec 27 05:59:54 zero volumio[819]: info: CorePlayQueue::getTrack 0 Dec 27 05:59:54 zero volumio[819]: info: CoreCommandRouter::volumioPushState Dec 27 05:59:54 zero volumio[819]: info: CorePlayQueue::getTrack 0 Dec 27 05:59:54 zero volumio[819]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Dec 27 05:59:54 zero volumio[819]: info: ------------------------------ 69ms Dec 27 05:59:54 zero volumio[819]: info: ------------------------------ 68ms Dec 27 05:59:58 zero volumio[819]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 27 05:59:58 zero volumio[819]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 27 06:00:06 zero volumio[819]: info: Enabling plugin volroon Dec 27 06:00:06 zero volumio[819]: info: Loading plugin "volroon"... Dec 27 06:00:07 zero volumio[819]: info: Preparing to generate the ALSA configuration file Dec 27 06:00:07 zero volumio[819]: info: Asound.conf file unchanged, so no further update is needed Dec 27 06:00:07 zero volumio[819]: info: Output device has changed, restarting MPD Dec 27 06:00:07 zero volumio[819]: info: Output device has changed, restarting Shairport Sync Dec 27 06:00:07 zero volumio[819]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 06:00:07 zero volumio[819]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 27 06:00:07 zero sudo[1401]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 27 06:00:07 zero sudo[1401]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 06:00:07 zero sudo[1403]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 27 06:00:07 zero sudo[1403]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 06:00:07 zero sudo[1401]: pam_unix(sudo:session): session closed for user root Dec 27 06:00:07 zero systemd[1]: Stopping Music Player Daemon... Dec 27 06:00:07 zero volumio[819]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 27 06:00:07 zero volumio[819]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAplayInfo Dec 27 06:00:07 zero volumio[819]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 06:00:07 zero volumio[819]: info: volroon::Output device has changed Dec 27 06:00:07 zero volumio[819]: info: PLUGIN START: volroon Dec 27 06:00:07 zero volumio[819]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAplayInfo Dec 27 06:00:07 zero volumio[819]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 27 06:00:07 zero sudo[1414]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Dec 27 06:00:07 zero sudo[1414]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 06:00:07 zero volumio[819]: info: volroon::Roon API Services Started Dec 27 06:00:07 zero volumio[819]: info: Done. Dec 27 06:00:07 zero sudo[1414]: pam_unix(sudo:session): session closed for user root Dec 27 06:00:07 zero volumio[819]: error: ::Cannot start Roon Bridge - Error: Error: Command failed: /usr/bin/sudo /bin/systemctl start roonbridge.service Dec 27 06:00:07 zero volumio[819]: Failed to start roonbridge.service: Unit roonbridge.service not found. Dec 27 06:00:07 zero volumio[819]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 27 06:00:07 zero volumio[819]: Error: Unable to resolve or reject the same promise twice Dec 27 06:00:07 zero volumio[819]: at Promise.reject (/data/plugins/music_service/volroon/node_modules/kew/kew.js:189:43) Dec 27 06:00:07 zero volumio[819]: at /data/plugins/music_service/volroon/index.js:400:10 Dec 27 06:00:07 zero volumio[819]: at ChildProcess.exithandler (child_process.js:315:5) Dec 27 06:00:07 zero volumio[819]: at ChildProcess.emit (events.js:315:20) Dec 27 06:00:07 zero volumio[819]: at maybeClose (internal/child_process.js:1048:16) Dec 27 06:00:07 zero volumio[819]: at Socket. (internal/child_process.js:439:11) Dec 27 06:00:07 zero volumio[819]: at Socket.emit (events.js:315:20) Dec 27 06:00:07 zero volumio[819]: at Pipe. (net.js:673:12) Dec 27 06:00:07 zero volumio[819]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 27 06:00:07 zero systemd[1]: mpd.service: Succeeded. Dec 27 06:00:07 zero systemd[1]: Stopped Music Player Daemon. Dec 27 06:00:07 zero systemd[1]: Starting Music Player Daemon... Dec 27 06:00:08 zero sudo[1424]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 27 06:00:08 zero sudo[1424]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 27 06:00:08 zero sudo[1424]: pam_unix(sudo:session): session closed for user root Dec 27 06:00:09 zero sudo[1442]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-27 05:59 Dec 27 06:00:09 zero sudo[1442]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="cc50ad4a2058d01de272214eb33827883bd2b7d8" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="502750e5d54ecf269d25125b622bfabc030fb553" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 12 Nov 2025 06:58:02 PM CET" VOLUMIO_VERSION="3.874" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="4ae6504ed6f22e44c01a6e93b16badbd"