Jan 12 08:44:00 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:00 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:00 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:44:00 volumio-test volumio[1294]: info: CoreStateMachine::getQueue Jan 12 08:44:00 volumio-test volumio[1294]: info: CorePlayQueue::getQueue Jan 12 08:44:02 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:02 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:02 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:44:02 volumio-test volumio[1294]: info: CoreStateMachine::getQueue Jan 12 08:44:02 volumio-test volumio[1294]: info: CorePlayQueue::getQueue Jan 12 08:44:04 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:04 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:04 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:44:04 volumio-test volumio[1294]: info: CoreStateMachine::getQueue Jan 12 08:44:04 volumio-test volumio[1294]: info: CorePlayQueue::getQueue Jan 12 08:44:04 volumio-test systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 11104. Jan 12 08:44:04 volumio-test systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Jan 12 08:44:04 volumio-test systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jan 12 08:44:05 volumio-test upmpdcli[2501]: Could not open config: /tmp/upmpdcli.conf Jan 12 08:44:05 volumio-test systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jan 12 08:44:05 volumio-test systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jan 12 08:44:05 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand add "https://edge56.live-sm.absolutradio.de/absolut-relax/stream/mp3" Jan 12 08:44:05 volumio-test volumio[1294]: error: updateQueue error: null Jan 12 08:44:05 volumio-test volumio[1294]: error: updateQueue error: null Jan 12 08:44:05 volumio-test volumio[1294]: info: ------------------------------ 10996ms Jan 12 08:44:05 volumio-test volumio[1294]: info: ------------------------------ 10995ms Jan 12 08:44:05 volumio-test volumio[1294]: info: sendMpdCommand stop took 9037 milliseconds Jan 12 08:44:05 volumio-test volumio[1294]: info: sendMpdCommand stop took 5692 milliseconds Jan 12 08:44:05 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand clear Jan 12 08:44:05 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand clear Jan 12 08:44:05 volumio-test volumio[1294]: info: Jan 12 08:44:05 volumio-test volumio[1294]: ---------------------------- MPD announces system playlist update Jan 12 08:44:05 volumio-test volumio[1294]: info: Ignoring MPD Status Update Jan 12 08:44:05 volumio-test volumio[1294]: info: Jan 12 08:44:05 volumio-test volumio[1294]: ---------------------------- MPD announces system playlist update Jan 12 08:44:05 volumio-test volumio[1294]: info: Ignoring MPD Status Update Jan 12 08:44:05 volumio-test volumio[1294]: info: Jan 12 08:44:05 volumio-test volumio[1294]: ---------------------------- MPD announces system playlist update Jan 12 08:44:05 volumio-test volumio[1294]: info: Ignoring MPD Status Update Jan 12 08:44:05 volumio-test volumio[1294]: info: Jan 12 08:44:05 volumio-test volumio[1294]: ---------------------------- MPD announces system playlist update Jan 12 08:44:05 volumio-test volumio[1294]: info: Ignoring MPD Status Update Jan 12 08:44:05 volumio-test volumio[1294]: error: updateQueue error: null Jan 12 08:44:05 volumio-test volumio[1294]: info: Jan 12 08:44:05 volumio-test volumio[1294]: ---------------------------- MPD announces system playlist update Jan 12 08:44:05 volumio-test volumio[1294]: info: Ignoring MPD Status Update Jan 12 08:44:05 volumio-test volumio[1294]: error: updateQueue error: null Jan 12 08:44:05 volumio-test volumio[1294]: info: sendMpdCommand add "https://edge56.live-sm.absolutradio.de/absolut-relax/stream/mp3" took 8 milliseconds Jan 12 08:44:05 volumio-test volumio[1294]: info: sendMpdCommand clear took 5 milliseconds Jan 12 08:44:05 volumio-test volumio[1294]: info: sendMpdCommand clear took 6 milliseconds Jan 12 08:44:05 volumio-test volumio[1294]: info: ------------------------------ 5ms Jan 12 08:44:05 volumio-test volumio[1294]: info: ------------------------------ 4ms Jan 12 08:44:05 volumio-test volumio[1294]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 12 08:44:05 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand play Jan 12 08:44:05 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand load "https://edge56.live-sm.absolutradio.de/absolut-relax/stream/mp3" Jan 12 08:44:05 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand load "http://icecast.radiofrance.fr/francemusiquelajazz-midfi.mp3" Jan 12 08:44:05 volumio-test volumio[1294]: info: Jan 12 08:44:05 volumio-test volumio[1294]: ---------------------------- MPD announces system playlist update Jan 12 08:44:05 volumio-test volumio[1294]: info: Ignoring MPD Status Update Jan 12 08:44:05 volumio-test volumio[1294]: info: Jan 12 08:44:05 volumio-test volumio[1294]: ---------------------------- MPD announces system playlist update Jan 12 08:44:05 volumio-test volumio[1294]: info: Ignoring MPD Status Update Jan 12 08:44:06 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:06 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:44:06 volumio-test volumio[1294]: info: CoreStateMachine::getQueue Jan 12 08:44:06 volumio-test volumio[1294]: info: CorePlayQueue::getQueue Jan 12 08:44:06 volumio-test volumio[1294]: info: CoreCommandRouter::volumioRemoveQueueItem Jan 12 08:44:06 volumio-test volumio[1294]: info: CoreStateMachine::removeQueueItem Jan 12 08:44:06 volumio-test volumio[1294]: info: CoreStateMachine::stop Jan 12 08:44:06 volumio-test volumio[1294]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 12 08:44:06 volumio-test volumio[1294]: info: CorePlayQueue::removeQueueItem 0 Jan 12 08:44:06 volumio-test volumio[1294]: info: CorePlayQueue::saveQueue Jan 12 08:44:06 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPushQueue Jan 12 08:44:08 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:08 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:08 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:44:08 volumio-test volumio[1294]: info: CoreStateMachine::getQueue Jan 12 08:44:08 volumio-test volumio[1294]: info: CorePlayQueue::getQueue Jan 12 08:44:09 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPlay Jan 12 08:44:09 volumio-test volumio[1294]: info: CoreStateMachine::play index undefined Jan 12 08:44:09 volumio-test volumio[1294]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 12 08:44:09 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:10 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:10 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:10 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:44:10 volumio-test volumio[1294]: info: CoreStateMachine::getQueue Jan 12 08:44:10 volumio-test volumio[1294]: info: CorePlayQueue::getQueue Jan 12 08:44:12 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:12 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:12 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:44:12 volumio-test volumio[1294]: info: CoreStateMachine::getQueue Jan 12 08:44:12 volumio-test volumio[1294]: info: CorePlayQueue::getQueue Jan 12 08:44:14 volumio-test volumio[1294]: info: Preload queue cleared Jan 12 08:44:14 volumio-test volumio[1294]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 12 08:44:14 volumio-test volumio[1294]: info: CoreStateMachine::ClearQueue Jan 12 08:44:14 volumio-test volumio[1294]: info: CoreStateMachine::stop Jan 12 08:44:14 volumio-test volumio[1294]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 12 08:44:14 volumio-test volumio[1294]: info: CorePlayQueue::clearPlayQueue Jan 12 08:44:14 volumio-test volumio[1294]: info: CorePlayQueue::saveQueue Jan 12 08:44:14 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPushQueue Jan 12 08:44:14 volumio-test volumio[1294]: info: CoreStateMachine::addQueueItems Jan 12 08:44:14 volumio-test volumio[1294]: info: CorePlayQueue::addQueueItems Jan 12 08:44:14 volumio-test volumio[1294]: info: Preload queue cleared Jan 12 08:44:14 volumio-test volumio[1294]: info: Adding Item to queue: http://icecast.radiofrance.fr/francemusiquelajazz-midfi.mp3 Jan 12 08:44:14 volumio-test volumio[1294]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Jan 12 08:44:14 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPushQueue Jan 12 08:44:14 volumio-test volumio[1294]: info: CorePlayQueue::saveQueue Jan 12 08:44:14 volumio-test volumio[1294]: info: CoreStateMachine::updateTrackBlock Jan 12 08:44:14 volumio-test volumio[1294]: info: CorePlayQueue::getTrackBlock Jan 12 08:44:14 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPlay Jan 12 08:44:14 volumio-test volumio[1294]: info: CoreStateMachine::play index 0 Jan 12 08:44:14 volumio-test volumio[1294]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 12 08:44:14 volumio-test volumio[1294]: info: CoreStateMachine::stop Jan 12 08:44:14 volumio-test volumio[1294]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 12 08:44:14 volumio-test volumio[1294]: info: CoreStateMachine::play index undefined Jan 12 08:44:14 volumio-test volumio[1294]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 12 08:44:14 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:14 volumio-test volumio[1294]: info: CoreStateMachine::startPlaybackTimer Jan 12 08:44:14 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:14 volumio-test volumio[1294]: info: [1768232654172] ControllerWebradio::clearAddPlayTrack Jan 12 08:44:14 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand stop Jan 12 08:44:14 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:14 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:14 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:44:14 volumio-test volumio[1294]: info: CoreStateMachine::getQueue Jan 12 08:44:14 volumio-test volumio[1294]: info: CorePlayQueue::getQueue Jan 12 08:44:15 volumio-test go-librespot[1488]: time="2026-01-12T08:44:15-07:00" level=trace msg="sent dealer ping" Jan 12 08:44:15 volumio-test go-librespot[1488]: time="2026-01-12T08:44:15-07:00" level=trace msg="received dealer pong" Jan 12 08:44:16 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:16 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:16 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:44:16 volumio-test volumio[1294]: info: CoreStateMachine::getQueue Jan 12 08:44:16 volumio-test volumio[1294]: info: CorePlayQueue::getQueue Jan 12 08:44:17 volumio-test volumio[1294]: error: updateQueue error: null Jan 12 08:44:17 volumio-test volumio[1294]: error: updateQueue error: null Jan 12 08:44:17 volumio-test volumio[1294]: error: updateQueue error: null Jan 12 08:44:17 volumio-test volumio[1294]: error: updateQueue error: null Jan 12 08:44:17 volumio-test volumio[1294]: error: updateQueue error: null Jan 12 08:44:17 volumio-test volumio[1294]: info: ------------------------------ 12097ms Jan 12 08:44:17 volumio-test volumio[1294]: info: ------------------------------ 12096ms Jan 12 08:44:17 volumio-test volumio[1294]: info: ------------------------------ 12096ms Jan 12 08:44:17 volumio-test volumio[1294]: info: sendMpdCommand play took 12094 milliseconds Jan 12 08:44:17 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand add "https://edge56.live-sm.absolutradio.de/absolut-relax/stream/mp3" Jan 12 08:44:17 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand add "http://icecast.radiofrance.fr/francemusiquelajazz-midfi.mp3" Jan 12 08:44:17 volumio-test volumio[1294]: info: ------------------------------ 12092ms Jan 12 08:44:17 volumio-test volumio[1294]: info: ------------------------------ 12091ms Jan 12 08:44:17 volumio-test volumio[1294]: info: sendMpdCommand stop took 3180 milliseconds Jan 12 08:44:17 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand clear Jan 12 08:44:17 volumio-test volumio[1294]: info: Jan 12 08:44:17 volumio-test volumio[1294]: ---------------------------- MPD announces system playlist update Jan 12 08:44:17 volumio-test volumio[1294]: info: Ignoring MPD Status Update Jan 12 08:44:17 volumio-test volumio[1294]: info: Jan 12 08:44:17 volumio-test volumio[1294]: ---------------------------- MPD announces system playlist update Jan 12 08:44:17 volumio-test volumio[1294]: info: Ignoring MPD Status Update Jan 12 08:44:17 volumio-test volumio[1294]: error: updateQueue error: null Jan 12 08:44:17 volumio-test volumio[1294]: info: sendMpdCommand add "https://edge56.live-sm.absolutradio.de/absolut-relax/stream/mp3" took 3 milliseconds Jan 12 08:44:17 volumio-test volumio[1294]: info: sendMpdCommand add "http://icecast.radiofrance.fr/francemusiquelajazz-midfi.mp3" took 7 milliseconds Jan 12 08:44:17 volumio-test volumio[1294]: info: sendMpdCommand clear took 6 milliseconds Jan 12 08:44:17 volumio-test volumio[1294]: info: ------------------------------ 6ms Jan 12 08:44:17 volumio-test volumio[1294]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 12 08:44:17 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand play Jan 12 08:44:17 volumio-test volumio[1294]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 12 08:44:17 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand play Jan 12 08:44:17 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand load "http://icecast.radiofrance.fr/francemusiquelajazz-midfi.mp3" Jan 12 08:44:17 volumio-test volumio[1294]: info: Jan 12 08:44:17 volumio-test volumio[1294]: ---------------------------- MPD announces system playlist update Jan 12 08:44:17 volumio-test volumio[1294]: info: Ignoring MPD Status Update Jan 12 08:44:17 volumio-test volumio[1294]: info: Jan 12 08:44:17 volumio-test volumio[1294]: ---------------------------- MPD announces system playlist update Jan 12 08:44:17 volumio-test volumio[1294]: info: Ignoring MPD Status Update Jan 12 08:44:17 volumio-test volumio[1294]: error: updateQueue error: null Jan 12 08:44:17 volumio-test volumio[1294]: info: ------------------------------ 8ms Jan 12 08:44:18 volumio-test volumio[1294]: info: sendMpdCommand play took 864 milliseconds Jan 12 08:44:18 volumio-test volumio[1294]: info: sendMpdCommand play took 864 milliseconds Jan 12 08:44:18 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand add "http://icecast.radiofrance.fr/francemusiquelajazz-midfi.mp3" Jan 12 08:44:18 volumio-test volumio[1294]: error: updateQueue error: null Jan 12 08:44:18 volumio-test volumio[1294]: error: updateQueue error: null Jan 12 08:44:18 volumio-test volumio[1294]: info: Jan 12 08:44:18 volumio-test volumio[1294]: ---------------------------- MPD announces system playlist update Jan 12 08:44:18 volumio-test volumio[1294]: info: Ignoring MPD Status Update Jan 12 08:44:18 volumio-test volumio[1294]: info: ------------------------------ 865ms Jan 12 08:44:18 volumio-test volumio[1294]: info: ------------------------------ 864ms Jan 12 08:44:18 volumio-test volumio[1294]: info: sendMpdCommand add "http://icecast.radiofrance.fr/francemusiquelajazz-midfi.mp3" took 1 milliseconds Jan 12 08:44:18 volumio-test volumio[1294]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 12 08:44:18 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand play Jan 12 08:44:18 volumio-test volumio[1294]: info: Jan 12 08:44:18 volumio-test volumio[1294]: ---------------------------- MPD announces system playlist update Jan 12 08:44:18 volumio-test volumio[1294]: info: Ignoring MPD Status Update Jan 12 08:44:18 volumio-test volumio[1294]: info: Jan 12 08:44:18 volumio-test volumio[1294]: ---------------------------- MPD announces system playlist update Jan 12 08:44:18 volumio-test volumio[1294]: info: Ignoring MPD Status Update Jan 12 08:44:18 volumio-test volumio[1294]: info: ------------------------------ 4ms Jan 12 08:44:18 volumio-test volumio[1294]: info: sendMpdCommand play took 4 milliseconds Jan 12 08:44:18 volumio-test volumio[1294]: info: ------------------------------ 3ms Jan 12 08:44:18 volumio-test volumio[1294]: info: ------------------------------ 2ms Jan 12 08:44:18 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:18 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:44:18 volumio-test volumio[1294]: info: CoreStateMachine::getQueue Jan 12 08:44:18 volumio-test volumio[1294]: info: CorePlayQueue::getQueue Jan 12 08:44:19 volumio-test volumio[1294]: info: Jan 12 08:44:19 volumio-test volumio[1294]: ---------------------------- MPD announces state update: player Jan 12 08:44:19 volumio-test volumio[1294]: info: ControllerMpd::getState Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand status Jan 12 08:44:19 volumio-test volumio[1294]: info: Jan 12 08:44:19 volumio-test volumio[1294]: ---------------------------- MPD announces state update: player Jan 12 08:44:19 volumio-test volumio[1294]: info: ControllerMpd::getState Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand status Jan 12 08:44:19 volumio-test volumio[1294]: info: Jan 12 08:44:19 volumio-test volumio[1294]: ---------------------------- MPD announces state update: player Jan 12 08:44:19 volumio-test volumio[1294]: info: ControllerMpd::getState Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand status Jan 12 08:44:19 volumio-test volumio[1294]: info: Jan 12 08:44:19 volumio-test volumio[1294]: ---------------------------- MPD announces state update: player Jan 12 08:44:19 volumio-test volumio[1294]: info: sendMpdCommand status took 18 milliseconds Jan 12 08:44:19 volumio-test volumio[1294]: info: ControllerMpd::getState Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand status Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::parseState Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 08:44:19 volumio-test volumio[1294]: info: Jan 12 08:44:19 volumio-test volumio[1294]: ---------------------------- MPD announces state update: player Jan 12 08:44:19 volumio-test volumio[1294]: info: ControllerMpd::getState Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand status Jan 12 08:44:19 volumio-test volumio[1294]: info: sendMpdCommand status took 19 milliseconds Jan 12 08:44:19 volumio-test volumio[1294]: info: sendMpdCommand status took 19 milliseconds Jan 12 08:44:19 volumio-test volumio[1294]: info: sendMpdCommand status took 4 milliseconds Jan 12 08:44:19 volumio-test volumio[1294]: info: sendMpdCommand playlistinfo took 3 milliseconds Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::parseState Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::parseState Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::parseState Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::parseTrackInfo Jan 12 08:44:19 volumio-test volumio[1294]: info: ControllerMpd::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::servicePushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"francemusiquelajazz-midfi.mp3","artist":null,"album":null,"uri":"http://icecast.radiofrance.fr/francemusiquelajazz-midfi.mp3","trackType":"mp3"} Jan 12 08:44:19 volumio-test volumio[1294]: verbose: CURRENT POSITION 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::syncState stateService play Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::syncState currentStatus stop Jan 12 08:44:19 volumio-test volumio[1294]: info: ------------------------------ 26ms Jan 12 08:44:19 volumio-test volumio[1294]: info: Jan 12 08:44:19 volumio-test volumio[1294]: ---------------------------- MPD announces state update: player Jan 12 08:44:19 volumio-test volumio[1294]: info: ControllerMpd::getState Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand status Jan 12 08:44:19 volumio-test volumio[1294]: info: sendMpdCommand status took 7 milliseconds Jan 12 08:44:19 volumio-test volumio[1294]: info: sendMpdCommand playlistinfo took 5 milliseconds Jan 12 08:44:19 volumio-test volumio[1294]: info: sendMpdCommand playlistinfo took 4 milliseconds Jan 12 08:44:19 volumio-test volumio[1294]: info: sendMpdCommand playlistinfo took 5 milliseconds Jan 12 08:44:19 volumio-test volumio[1294]: info: sendMpdCommand status took 2 milliseconds Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::parseState Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::parseTrackInfo Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::parseTrackInfo Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::parseTrackInfo Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::parseState Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 08:44:19 volumio-test volumio[1294]: info: ControllerMpd::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::servicePushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"francemusiquelajazz-midfi.mp3","artist":null,"album":null,"uri":"http://icecast.radiofrance.fr/francemusiquelajazz-midfi.mp3","trackType":"mp3"} Jan 12 08:44:19 volumio-test volumio[1294]: verbose: CURRENT POSITION 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::syncState stateService play Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::syncState currentStatus play Jan 12 08:44:19 volumio-test volumio[1294]: info: Received an update from plugin. extracting info from payload Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPushState Jan 12 08:44:19 volumio-test volumio[1294]: info: ControllerMpd::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::servicePushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"francemusiquelajazz-midfi.mp3","artist":null,"album":null,"uri":"http://icecast.radiofrance.fr/francemusiquelajazz-midfi.mp3","trackType":"mp3"} Jan 12 08:44:19 volumio-test volumio[1294]: verbose: CURRENT POSITION 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::syncState stateService play Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::syncState currentStatus play Jan 12 08:44:19 volumio-test volumio[1294]: info: Received an update from plugin. extracting info from payload Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPushState Jan 12 08:44:19 volumio-test volumio[1294]: info: ControllerMpd::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::servicePushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"francemusiquelajazz-midfi.mp3","artist":null,"album":null,"uri":"http://icecast.radiofrance.fr/francemusiquelajazz-midfi.mp3","trackType":"mp3"} Jan 12 08:44:19 volumio-test volumio[1294]: verbose: CURRENT POSITION 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::syncState stateService play Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::syncState currentStatus play Jan 12 08:44:19 volumio-test volumio[1294]: info: Received an update from plugin. extracting info from payload Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPushState Jan 12 08:44:19 volumio-test volumio[1294]: info: ------------------------------ 106ms Jan 12 08:44:19 volumio-test volumio[1294]: info: ------------------------------ 106ms Jan 12 08:44:19 volumio-test volumio[1294]: info: ------------------------------ 93ms Jan 12 08:44:19 volumio-test volumio[1294]: info: sendMpdCommand playlistinfo took 83 milliseconds Jan 12 08:44:19 volumio-test volumio[1294]: info: sendMpdCommand playlistinfo took 82 milliseconds Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::parseTrackInfo Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::parseTrackInfo Jan 12 08:44:19 volumio-test volumio[1294]: info: ControllerMpd::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::servicePushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"francemusiquelajazz-midfi.mp3","artist":null,"album":null,"uri":"http://icecast.radiofrance.fr/francemusiquelajazz-midfi.mp3","trackType":"mp3"} Jan 12 08:44:19 volumio-test volumio[1294]: verbose: CURRENT POSITION 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::syncState stateService play Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::syncState currentStatus play Jan 12 08:44:19 volumio-test volumio[1294]: info: Received an update from plugin. extracting info from payload Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPushState Jan 12 08:44:19 volumio-test volumio[1294]: info: ControllerMpd::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::servicePushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"francemusiquelajazz-midfi.mp3","artist":null,"album":null,"uri":"http://icecast.radiofrance.fr/francemusiquelajazz-midfi.mp3","trackType":"mp3"} Jan 12 08:44:19 volumio-test volumio[1294]: verbose: CURRENT POSITION 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::syncState stateService play Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::syncState currentStatus play Jan 12 08:44:19 volumio-test volumio[1294]: info: Received an update from plugin. extracting info from payload Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPushState Jan 12 08:44:19 volumio-test volumio[1294]: info: ------------------------------ 143ms Jan 12 08:44:19 volumio-test volumio[1294]: info: ------------------------------ 139ms Jan 12 08:44:19 volumio-test volumio[1294]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Jan 12 08:44:19 volumio-test volumio[1294]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Jan 12 08:44:19 volumio-test volumio[1294]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Jan 12 08:44:19 volumio-test volumio[1294]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Jan 12 08:44:19 volumio-test volumio[1294]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Jan 12 08:44:19 volumio-test volumio[1294]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Jan 12 08:44:19 volumio-test volumio[1294]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Jan 12 08:44:19 volumio-test volumio[1294]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Jan 12 08:44:19 volumio-test volumio[1294]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Jan 12 08:44:19 volumio-test volumio[1294]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Jan 12 08:44:19 volumio-test volumio[1294]: info: Jan 12 08:44:19 volumio-test volumio[1294]: ---------------------------- MPD announces system playlist update Jan 12 08:44:19 volumio-test volumio[1294]: info: Ignoring MPD Status Update Jan 12 08:44:19 volumio-test volumio[1294]: info: Jan 12 08:44:19 volumio-test volumio[1294]: ---------------------------- MPD announces state update: player Jan 12 08:44:19 volumio-test volumio[1294]: info: ControllerMpd::getState Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand status Jan 12 08:44:19 volumio-test volumio[1294]: info: Jan 12 08:44:19 volumio-test volumio[1294]: ---------------------------- MPD announces system playlist update Jan 12 08:44:19 volumio-test volumio[1294]: info: Ignoring MPD Status Update Jan 12 08:44:19 volumio-test volumio[1294]: info: Jan 12 08:44:19 volumio-test volumio[1294]: ---------------------------- MPD announces state update: player Jan 12 08:44:19 volumio-test volumio[1294]: info: ControllerMpd::getState Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand status Jan 12 08:44:19 volumio-test volumio[1294]: info: Jan 12 08:44:19 volumio-test volumio[1294]: ---------------------------- MPD announces system playlist update Jan 12 08:44:19 volumio-test volumio[1294]: info: Ignoring MPD Status Update Jan 12 08:44:19 volumio-test volumio[1294]: info: Jan 12 08:44:19 volumio-test volumio[1294]: ---------------------------- MPD announces state update: player Jan 12 08:44:19 volumio-test volumio[1294]: info: ControllerMpd::getState Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand status Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::volumioRemoveQueueItem Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::removeQueueItem Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::stop Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::stPlaybackTimer Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::updateTrackBlock Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrackBlock Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::serviceStop Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::serviceStop Jan 12 08:44:19 volumio-test volumio[1294]: info: [1768232659384] ControllerWebradio::stop Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand stop Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::removeQueueItem 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::saveQueue Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPushQueue Jan 12 08:44:19 volumio-test volumio[1294]: info: ------------------------------ 33ms Jan 12 08:44:19 volumio-test volumio[1294]: info: sendMpdCommand status took 33 milliseconds Jan 12 08:44:19 volumio-test volumio[1294]: info: ------------------------------ 31ms Jan 12 08:44:19 volumio-test volumio[1294]: info: sendMpdCommand status took 30 milliseconds Jan 12 08:44:19 volumio-test volumio[1294]: info: ------------------------------ 29ms Jan 12 08:44:19 volumio-test volumio[1294]: info: sendMpdCommand status took 28 milliseconds Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::parseState Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::parseState Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::parseState Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 08:44:19 volumio-test volumio[1294]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Jan 12 08:44:19 volumio-test volumio[1294]: info: Jan 12 08:44:19 volumio-test volumio[1294]: ---------------------------- MPD announces state update: player Jan 12 08:44:19 volumio-test volumio[1294]: info: sendMpdCommand stop took 28 milliseconds Jan 12 08:44:19 volumio-test volumio[1294]: info: ControllerMpd::getState Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand status Jan 12 08:44:19 volumio-test volumio[1294]: info: sendMpdCommand playlistinfo took 11 milliseconds Jan 12 08:44:19 volumio-test volumio[1294]: info: sendMpdCommand playlistinfo took 11 milliseconds Jan 12 08:44:19 volumio-test volumio[1294]: info: sendMpdCommand playlistinfo took 12 milliseconds Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::parseTrackInfo Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::parseTrackInfo Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::parseTrackInfo Jan 12 08:44:19 volumio-test volumio[1294]: info: ControllerMpd::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::servicePushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: verbose: STATE SERVICE {"status":"play","position":0,"seek":988,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"francemusiquelajazz-midfi.mp3","artist":"francemusiquelajazz-midfi.mp3","album":null,"uri":"http://icecast.radiofrance.fr/francemusiquelajazz-midfi.mp3","trackType":"mp3"} Jan 12 08:44:19 volumio-test volumio[1294]: verbose: CURRENT POSITION 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::syncState stateService play Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::syncState currentStatus stop Jan 12 08:44:19 volumio-test volumio[1294]: info: ControllerMpd::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::servicePushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: verbose: STATE SERVICE {"status":"play","position":0,"seek":988,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"francemusiquelajazz-midfi.mp3","artist":"francemusiquelajazz-midfi.mp3","album":null,"uri":"http://icecast.radiofrance.fr/francemusiquelajazz-midfi.mp3","trackType":"mp3"} Jan 12 08:44:19 volumio-test volumio[1294]: verbose: CURRENT POSITION 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::syncState stateService play Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::syncState currentStatus play Jan 12 08:44:19 volumio-test volumio[1294]: info: Received an update from plugin. extracting info from payload Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPushState Jan 12 08:44:19 volumio-test volumio[1294]: info: ControllerMpd::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::servicePushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: verbose: STATE SERVICE {"status":"play","position":0,"seek":988,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"francemusiquelajazz-midfi.mp3","artist":"francemusiquelajazz-midfi.mp3","album":null,"uri":"http://icecast.radiofrance.fr/francemusiquelajazz-midfi.mp3","trackType":"mp3"} Jan 12 08:44:19 volumio-test volumio[1294]: verbose: CURRENT POSITION 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::syncState stateService play Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::syncState currentStatus play Jan 12 08:44:19 volumio-test volumio[1294]: info: Received an update from plugin. extracting info from payload Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPushState Jan 12 08:44:19 volumio-test volumio[1294]: info: ------------------------------ 62ms Jan 12 08:44:19 volumio-test volumio[1294]: info: ------------------------------ 90ms Jan 12 08:44:19 volumio-test volumio[1294]: info: ------------------------------ 90ms Jan 12 08:44:19 volumio-test volumio[1294]: info: Jan 12 08:44:19 volumio-test volumio[1294]: ---------------------------- MPD announces state update: player Jan 12 08:44:19 volumio-test volumio[1294]: info: ControllerMpd::getState Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand status Jan 12 08:44:19 volumio-test volumio[1294]: info: Jan 12 08:44:19 volumio-test volumio[1294]: ---------------------------- MPD announces state update: player Jan 12 08:44:19 volumio-test volumio[1294]: info: ControllerMpd::getState Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand status Jan 12 08:44:19 volumio-test volumio[1294]: info: sendMpdCommand status took 52 milliseconds Jan 12 08:44:19 volumio-test volumio[1294]: info: sendMpdCommand status took 3 milliseconds Jan 12 08:44:19 volumio-test volumio[1294]: info: sendMpdCommand status took 2 milliseconds Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::parseState Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::parseState Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::parseState Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 08:44:19 volumio-test volumio[1294]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Jan 12 08:44:19 volumio-test volumio[1294]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Jan 12 08:44:19 volumio-test volumio[1294]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Jan 12 08:44:19 volumio-test volumio[1294]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Jan 12 08:44:19 volumio-test volumio[1294]: info: sendMpdCommand playlistinfo took 21 milliseconds Jan 12 08:44:19 volumio-test volumio[1294]: info: sendMpdCommand playlistinfo took 21 milliseconds Jan 12 08:44:19 volumio-test volumio[1294]: info: sendMpdCommand playlistinfo took 22 milliseconds Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::parseTrackInfo Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::parseTrackInfo Jan 12 08:44:19 volumio-test volumio[1294]: verbose: ControllerMpd::parseTrackInfo Jan 12 08:44:19 volumio-test volumio[1294]: info: ControllerMpd::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::servicePushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: 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":"francemusiquelajazz-midfi.mp3","artist":"francemusiquelajazz-midfi.mp3","album":null,"uri":"http://icecast.radiofrance.fr/francemusiquelajazz-midfi.mp3","trackType":"mp3"} Jan 12 08:44:19 volumio-test volumio[1294]: verbose: CURRENT POSITION 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::syncState stateService stop Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::syncState currentStatus play Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::play index undefined Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPushState Jan 12 08:44:19 volumio-test volumio[1294]: info: ControllerMpd::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::servicePushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: 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":"francemusiquelajazz-midfi.mp3","artist":"francemusiquelajazz-midfi.mp3","album":null,"uri":"http://icecast.radiofrance.fr/francemusiquelajazz-midfi.mp3","trackType":"mp3"} Jan 12 08:44:19 volumio-test volumio[1294]: verbose: CURRENT POSITION 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::syncState stateService stop Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::syncState currentStatus stop Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPushState Jan 12 08:44:19 volumio-test volumio[1294]: info: No code Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPushState Jan 12 08:44:19 volumio-test volumio[1294]: info: ControllerMpd::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::servicePushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: 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":"francemusiquelajazz-midfi.mp3","artist":"francemusiquelajazz-midfi.mp3","album":null,"uri":"http://icecast.radiofrance.fr/francemusiquelajazz-midfi.mp3","trackType":"mp3"} Jan 12 08:44:19 volumio-test volumio[1294]: verbose: CURRENT POSITION 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::syncState stateService stop Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::syncState currentStatus stop Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPushState Jan 12 08:44:19 volumio-test volumio[1294]: info: No code Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreStateMachine::pushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: CoreCommandRouter::volumioPushState Jan 12 08:44:19 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:19 volumio-test volumio[1294]: info: ------------------------------ 162ms Jan 12 08:44:19 volumio-test volumio[1294]: info: ------------------------------ 113ms Jan 12 08:44:19 volumio-test volumio[1294]: info: ------------------------------ 111ms Jan 12 08:44:19 volumio-test volumio[1294]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Jan 12 08:44:19 volumio-test volumio[1294]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Jan 12 08:44:19 volumio-test volumio[1294]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Jan 12 08:44:19 volumio-test volumio[1294]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Jan 12 08:44:19 volumio-test volumio[1294]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Jan 12 08:44:19 volumio-test volumio[1294]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Jan 12 08:44:19 volumio-test volumio[1294]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Jan 12 08:44:19 volumio-test volumio[1294]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Jan 12 08:44:20 volumio-test systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 11105. Jan 12 08:44:20 volumio-test systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Jan 12 08:44:20 volumio-test systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jan 12 08:44:20 volumio-test upmpdcli[2519]: Could not open config: /tmp/upmpdcli.conf Jan 12 08:44:20 volumio-test systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jan 12 08:44:20 volumio-test systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jan 12 08:44:20 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:20 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:20 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:44:20 volumio-test volumio[1294]: info: CoreStateMachine::getQueue Jan 12 08:44:20 volumio-test volumio[1294]: info: CorePlayQueue::getQueue Jan 12 08:44:22 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:22 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:22 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:44:22 volumio-test volumio[1294]: info: CoreStateMachine::getQueue Jan 12 08:44:22 volumio-test volumio[1294]: info: CorePlayQueue::getQueue Jan 12 08:44:22 volumio-test go-librespot[1488]: time="2026-01-12T08:44:22-07:00" level=trace msg="received accesspoint ping" Jan 12 08:44:23 volumio-test go-librespot[1488]: time="2026-01-12T08:44:23-07:00" level=trace msg="received accesspoint pong ack" Jan 12 08:44:24 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:24 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:24 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:44:24 volumio-test volumio[1294]: info: CoreStateMachine::getQueue Jan 12 08:44:24 volumio-test volumio[1294]: info: CorePlayQueue::getQueue Jan 12 08:44:26 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:26 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:26 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:44:26 volumio-test volumio[1294]: info: CoreStateMachine::getQueue Jan 12 08:44:26 volumio-test volumio[1294]: info: CorePlayQueue::getQueue Jan 12 08:44:28 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:28 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:28 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:44:28 volumio-test volumio[1294]: info: CoreStateMachine::getQueue Jan 12 08:44:28 volumio-test volumio[1294]: info: CorePlayQueue::getQueue Jan 12 08:44:30 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:30 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:30 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:44:30 volumio-test volumio[1294]: info: CoreStateMachine::getQueue Jan 12 08:44:30 volumio-test volumio[1294]: info: CorePlayQueue::getQueue Jan 12 08:44:32 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:32 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:32 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:44:32 volumio-test volumio[1294]: info: CoreStateMachine::getQueue Jan 12 08:44:32 volumio-test volumio[1294]: info: CorePlayQueue::getQueue Jan 12 08:44:34 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:34 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:34 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:44:34 volumio-test volumio[1294]: info: CoreStateMachine::getQueue Jan 12 08:44:34 volumio-test volumio[1294]: info: CorePlayQueue::getQueue Jan 12 08:44:35 volumio-test systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 11106. Jan 12 08:44:35 volumio-test systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Jan 12 08:44:35 volumio-test systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jan 12 08:44:35 volumio-test upmpdcli[2552]: Could not open config: /tmp/upmpdcli.conf Jan 12 08:44:35 volumio-test systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jan 12 08:44:35 volumio-test systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jan 12 08:44:36 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:36 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:36 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:44:36 volumio-test volumio[1294]: info: CoreStateMachine::getQueue Jan 12 08:44:36 volumio-test volumio[1294]: info: CorePlayQueue::getQueue Jan 12 08:44:38 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:38 volumio-test volumio[1294]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:38 volumio-test volumio[1294]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:44:38 volumio-test volumio[1294]: info: CoreStateMachine::getQueue Jan 12 08:44:38 volumio-test volumio[1294]: info: CorePlayQueue::getQueue Jan 12 08:44:39 volumio-test volumio[1294]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 12 08:44:39 volumio-test volumio[1294]: Error Jan 12 08:44:39 volumio-test volumio[1294]: at /volumio/app/plugins/music_service/webradio/index.js:427:31 Jan 12 08:44:39 volumio-test volumio[1294]: at Request.handleRequestResponse [as _callback] (/volumio/node_modules/unirest/index.js:444:15) Jan 12 08:44:39 volumio-test volumio[1294]: at self.callback (/volumio/node_modules/request/request.js:185:22) Jan 12 08:44:39 volumio-test volumio[1294]: at Request.emit (node:events:514:28) Jan 12 08:44:39 volumio-test volumio[1294]: at Request.onRequestError (/volumio/node_modules/request/request.js:877:8) Jan 12 08:44:39 volumio-test volumio[1294]: at ClientRequest.emit (node:events:514:28) Jan 12 08:44:39 volumio-test volumio[1294]: at Socket.socketErrorListener (node:_http_client:495:9) Jan 12 08:44:39 volumio-test volumio[1294]: at Socket.emit (node:events:514:28) Jan 12 08:44:39 volumio-test volumio[1294]: at emitErrorNT (node:internal/streams/destroy:151:8) Jan 12 08:44:39 volumio-test volumio[1294]: at emitErrorCloseNT (node:internal/streams/destroy:116:3) Jan 12 08:44:39 volumio-test volumio[1294]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 12 08:44:40 volumio-test sudo[2569]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-12 08:43' Jan 12 08:44:40 volumio-test sudo[2569]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 08:44:40 volumio-test sudo[2569]: pam_unix(sudo:session): session closed for user root Jan 12 08:44:40 volumio-test volumio-remote-updater[686]: [2026-01-12 08:44:40] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 12 08:44:40 volumio-test volumio-remote-updater[686]: [2026-01-12 08:44:40] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 12 08:44:40 volumio-test go-librespot[1488]: time="2026-01-12T08:44:40-07:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Jan 12 08:44:40 volumio-test systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 12 08:44:40 volumio-test systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 12 08:44:40 volumio-test systemd[1]: volumio.service: Consumed 1min 31.272s CPU time. Jan 12 08:44:40 volumio-test systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 12 08:44:40 volumio-test systemd[1]: dynamicswap.service: Deactivated successfully. Jan 12 08:44:40 volumio-test systemd[1]: volumio.service: Scheduled restart job, restart counter is at 3. Jan 12 08:44:40 volumio-test systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 12 08:44:40 volumio-test systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 12 08:44:40 volumio-test systemd[1]: volumio.service: Consumed 1min 31.272s CPU time. Jan 12 08:44:40 volumio-test systemd[1]: Started volumio.service - Volumio Backend Module. Jan 12 08:44:40 volumio-test systemd[1]: dynamicswap.service: Deactivated successfully. Jan 12 08:44:42 volumio-test volumio[2601]: info: ------------------------------------------- Jan 12 08:44:42 volumio-test volumio[2601]: info: ----- Volumio3 ---- Jan 12 08:44:42 volumio-test volumio[2601]: info: ------------------------------------------- Jan 12 08:44:42 volumio-test volumio[2601]: info: ----- System startup ---- Jan 12 08:44:42 volumio-test volumio[2601]: info: ------------------------------------------- Jan 12 08:44:43 volumio-test volumio[2601]: info: MYVOLUMIO Environment detected Jan 12 08:44:43 volumio-test volumio[2601]: info: Plugin folders cleanup Jan 12 08:44:43 volumio-test volumio[2601]: info: Scanning into folder /volumio/app/plugins/ Jan 12 08:44:43 volumio-test volumio[2601]: info: Scanning category audio_interface Jan 12 08:44:43 volumio-test volumio[2601]: info: Scanning category miscellanea Jan 12 08:44:43 volumio-test volumio[2601]: info: Scanning category music_service Jan 12 08:44:43 volumio-test volumio[2601]: info: Scanning category plugins.json Jan 12 08:44:43 volumio-test volumio[2601]: info: Scanning category system_controller Jan 12 08:44:43 volumio-test volumio[2601]: info: Scanning category user_interface Jan 12 08:44:43 volumio-test volumio[2601]: info: Scanning into folder /data/plugins/ Jan 12 08:44:43 volumio-test volumio[2601]: info: Scanning category music_service Jan 12 08:44:43 volumio-test volumio[2601]: info: Scanning category system_controller Jan 12 08:44:43 volumio-test volumio[2601]: info: Scanning category user_interface Jan 12 08:44:43 volumio-test volumio[2601]: info: Plugin folders cleanup completed Jan 12 08:44:43 volumio-test volumio[2601]: info: ------------------------------------------- Jan 12 08:44:43 volumio-test volumio[2601]: info: ----- Core plugins startup ---- Jan 12 08:44:43 volumio-test volumio[2601]: info: ------------------------------------------- Jan 12 08:44:43 volumio-test volumio[2601]: info: Loading plugins from folder /volumio/app/plugins/ Jan 12 08:44:43 volumio-test volumio[2601]: info: Adding plugin upnp to MyMusic Plugins Jan 12 08:44:43 volumio-test volumio[2601]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 12 08:44:43 volumio-test volumio[2601]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 12 08:44:43 volumio-test volumio[2601]: info: Loading plugins from folder /data/plugins/ Jan 12 08:44:43 volumio-test volumio[2601]: info: Loading plugin "system"... Jan 12 08:44:43 volumio-test volumio[2601]: info: Loading plugin "appearance"... Jan 12 08:44:45 volumio-test go-librespot[1488]: time="2026-01-12T08:44:45-07:00" level=trace msg="sent dealer ping" Jan 12 08:44:45 volumio-test volumio-remote-updater[686]: [2026-01-12 08:44:45] [connect] Successful connection Jan 12 08:44:45 volumio-test volumio[2601]: info: Loading plugin "network"... Jan 12 08:44:45 volumio-test volumio[2601]: info: Refreshing Cached IP Addresses Jan 12 08:44:45 volumio-test go-librespot[1488]: time="2026-01-12T08:44:45-07:00" level=trace msg="received dealer pong" Jan 12 08:44:45 volumio-test sudo[2632]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 12 08:44:45 volumio-test sudo[2632]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 08:44:45 volumio-test volumio[2601]: info: Loading plugin "services"... Jan 12 08:44:45 volumio-test sudo[2632]: pam_unix(sudo:session): session closed for user root Jan 12 08:44:45 volumio-test volumio[2601]: info: Loading plugin "alsa_controller"... Jan 12 08:44:45 volumio-test sudo[2634]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 12 08:44:45 volumio-test sudo[2634]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 08:44:45 volumio-test sudo[2634]: pam_unix(sudo:session): session closed for user root Jan 12 08:44:45 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 12 08:44:45 volumio-test volumio[2601]: info: Loading plugin "wizard"... Jan 12 08:44:45 volumio-test volumio[2601]: info: Loading plugin "networkfs"... Jan 12 08:44:45 volumio-test volumio[2601]: info: Starting Udev Watcher for removable devices Jan 12 08:44:45 volumio-test volumio[2601]: info: Ignoring mount for partition: boot Jan 12 08:44:45 volumio-test volumio[2601]: info: Ignoring mount for partition: volumio Jan 12 08:44:45 volumio-test volumio[2601]: info: Ignoring mount for partition: volumio_data Jan 12 08:44:45 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 12 08:44:45 volumio-test volumio[2601]: info: Loading plugin "volumio_command_line_client"... Jan 12 08:44:45 volumio-test volumio[2601]: info: Plugin upnp is not enabled Jan 12 08:44:45 volumio-test volumio[2601]: info: Loading plugin "my_music"... Jan 12 08:44:45 volumio-test volumio[2601]: info: Loading plugin "mpd"... Jan 12 08:44:46 volumio-test volumio[2601]: info: Plugin upnp_browser is not enabled Jan 12 08:44:46 volumio-test volumio[2601]: info: Loading plugin "alarm-clock"... Jan 12 08:44:46 volumio-test volumio[2601]: info: Plugin airplay_emulation is not enabled Jan 12 08:44:46 volumio-test volumio[2601]: info: Loading plugin "last_100"... Jan 12 08:44:46 volumio-test volumio[2601]: info: Loading plugin "webradio"... Jan 12 08:44:47 volumio-test volumio[2601]: info: Loading plugin "i2s_dacs"... Jan 12 08:44:47 volumio-test volumio[2601]: info: Loading plugin "volumiodiscovery"... Jan 12 08:44:47 volumio-test volumio[2601]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 12 08:44:47 volumio-test volumio[2601]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 12 08:44:47 volumio-test volumio[2601]: *** WARNING *** For more information see Jan 12 08:44:47 volumio-test volumio[2601]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 12 08:44:47 volumio-test volumio[2601]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 12 08:44:47 volumio-test volumio[2601]: *** WARNING *** For more information see Jan 12 08:44:47 volumio-test node[2601]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 12 08:44:47 volumio-test node[2601]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 12 08:44:47 volumio-test node[2601]: *** WARNING *** For more information see Jan 12 08:44:47 volumio-test node[2601]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 12 08:44:47 volumio-test node[2601]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 12 08:44:47 volumio-test node[2601]: *** WARNING *** For more information see Jan 12 08:44:47 volumio-test volumio[2601]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 12 08:44:47 volumio-test volumio[2601]: info: Discovery: Started advertising with name: Volumio Test Jan 12 08:44:47 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 12 08:44:47 volumio-test volumio[2601]: info: Loading plugin "spop"... Jan 12 08:44:49 volumio-test volumio[2601]: info: Loading plugin "autostart"... Jan 12 08:44:49 volumio-test volumio[2601]: info: Applying required configuration parameters for plugin autostart Jan 12 08:44:49 volumio-test volumio[2601]: info: AutoStart - onVolumioStart - read config.json Jan 12 08:44:49 volumio-test volumio[2601]: info: Loading plugin "outputs"... Jan 12 08:44:49 volumio-test volumio[2601]: info: Loading plugin "albumart"... Jan 12 08:44:49 volumio-test volumio[2601]: info: Plugin example_plugin is not enabled Jan 12 08:44:49 volumio-test volumio[2601]: info: Loading plugin "inputs"... Jan 12 08:44:49 volumio-test volumio[2601]: info: Loading plugin "updater_comm"... Jan 12 08:44:49 volumio-test volumio[2601]: info: Plugin mpdemulation is not enabled Jan 12 08:44:49 volumio-test volumio[2601]: info: Loading plugin "rest_api"... Jan 12 08:44:49 volumio-test volumio[2601]: info: Loading plugin "websocket"... Jan 12 08:44:49 volumio-test volumio[2601]: info: Starting Socket.io Server version 1.7.4 Jan 12 08:44:49 volumio-test volumio[2601]: info: Loading plugin "pandora"... Jan 12 08:44:50 volumio-test volumio[2664]: Forking 3 albumart workers Jan 12 08:44:50 volumio-test systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 11107. Jan 12 08:44:50 volumio-test systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Jan 12 08:44:50 volumio-test systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jan 12 08:44:50 volumio-test upmpdcli[2704]: Could not open config: /tmp/upmpdcli.conf Jan 12 08:44:50 volumio-test systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jan 12 08:44:50 volumio-test systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jan 12 08:44:51 volumio-test volumio[2601]: info: Applying required configuration parameters for plugin pandora Jan 12 08:44:51 volumio-test volumio[2601]: info: Loading plugin "Systeminfo"... Jan 12 08:44:51 volumio-test volumio[2676]: Starting albumart workers Jan 12 08:44:51 volumio-test volumio[2675]: Starting albumart workers Jan 12 08:44:51 volumio-test volumio[2674]: Starting albumart workers Jan 12 08:44:52 volumio-test volumio[2601]: info: Loading i18n strings for locale en Jan 12 08:44:52 volumio-test volumio[2601]: Updating browse sources language Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreCommandRouter::initPlayerControls Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 08:44:52 volumio-test volumio[2601]: Express server listening on port 3000 Jan 12 08:44:52 volumio-test volumio[2601]: [Metrics] WebUI: 10s 232.11ms Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreStateMachine::resetVolumioState Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreStateMachine::getcurrentVolume Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreCommandRouter::volumioRetrievevolume Jan 12 08:44:52 volumio-test volumio[2601]: info: Volumio Network Manager: Network status updated: 1 Jan 12 08:44:52 volumio-test volumio[2601]: verbose: New Socket.io Connection to 192.168.1.139 from 192.168.1.64 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Jan 12 08:44:52 volumio-test volumio[2601]: verbose: New Socket.io Connection to 192.168.1.139 from 192.168.1.64 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 08:44:52 volumio-test volumio[2601]: info: Reloading queue from file Jan 12 08:44:52 volumio-test volumio[2601]: verbose: New Socket.io Connection to 192.168.1.139:3000 from 192.168.1.198 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 12 08:44:52 volumio-test volumio[2601]: info: VolumeController:: Volume=35 Mute =false Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreStateMachine::pushState Jan 12 08:44:52 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreCommandRouter::volumioPushState Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreStateMachine::updateTrackBlock Jan 12 08:44:52 volumio-test volumio[2601]: info: CorePlayQueue::getTrackBlock Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreCommandRouter::volumioRetrievevolume Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreStateMachine::setRepeat true single undefined Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreStateMachine::pushState Jan 12 08:44:52 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreCommandRouter::volumioPushState Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreStateMachine::setRandom true Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreStateMachine::pushState Jan 12 08:44:52 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreCommandRouter::volumioPushState Jan 12 08:44:52 volumio-test volumio[2601]: info: Setting Device type: Raspberry PI Jan 12 08:44:52 volumio-test volumio[2601]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Jan 12 08:44:52 volumio-test volumio[2601]: info: USB Boot Capable - System SBC Revision found in cpuinfo: a22082 Jan 12 08:44:52 volumio-test volumio[2601]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Jan 12 08:44:52 volumio-test volumio[2601]: info: Completed loading Core Plugins Jan 12 08:44:52 volumio-test volumio[2601]: info: Preparing to generate the ALSA configuration file Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:52 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:52 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:52 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:52 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreStateMachine::getQueue Jan 12 08:44:52 volumio-test volumio[2601]: info: CorePlayQueue::getQueue Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreStateMachine::getQueue Jan 12 08:44:52 volumio-test volumio[2601]: info: CorePlayQueue::getQueue Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:44:52 volumio-test volumio[2601]: info: CoreStateMachine::getQueue Jan 12 08:44:52 volumio-test volumio[2601]: info: CorePlayQueue::getQueue Jan 12 08:44:53 volumio-test volumio[2601]: info: VolumeController:: Volume=35 Mute =false Jan 12 08:44:53 volumio-test volumio[2601]: info: CoreStateMachine::pushState Jan 12 08:44:53 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:53 volumio-test volumio[2601]: info: CoreCommandRouter::volumioPushState Jan 12 08:44:53 volumio-test volumio[2601]: info: Asound.conf file unchanged, so no further update is needed Jan 12 08:44:53 volumio-test volumio[2601]: info: Output device has changed, restarting MPD Jan 12 08:44:53 volumio-test volumio[2601]: info: ___________ START PLUGINS ___________ Jan 12 08:44:53 volumio-test sudo[2740]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 12 08:44:53 volumio-test sudo[2740]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 08:44:53 volumio-test volumio[2601]: info: ControllerMpd::onStart: Initializing MPD Jan 12 08:44:53 volumio-test volumio[2601]: info: Creating MPD Configuration file Jan 12 08:44:53 volumio-test sudo[2740]: pam_unix(sudo:session): session closed for user root Jan 12 08:44:53 volumio-test sudo[2742]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 12 08:44:53 volumio-test sudo[2742]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 08:44:53 volumio-test volumio[2601]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 12 08:44:53 volumio-test volumio[2601]: info: [1768232693072] CoreMusicLibrary::Adding element Last_100 Jan 12 08:44:53 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 12 08:44:53 volumio-test volumio[2601]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 12 08:44:53 volumio-test volumio[2601]: info: [1768232693076] CoreMusicLibrary::Adding element Webradio Jan 12 08:44:53 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 12 08:44:53 volumio-test sudo[2746]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 12 08:44:53 volumio-test sudo[2746]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 08:44:53 volumio-test sudo[2746]: pam_unix(sudo:session): session closed for user root Jan 12 08:44:53 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 12 08:44:53 volumio-test volumio[2601]: info: Initializing BBC Radios Jan 12 08:44:53 volumio-test sudo[2748]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 12 08:44:53 volumio-test sudo[2748]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 08:44:53 volumio-test systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 12 08:44:53 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 12 08:44:53 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 08:44:53 volumio-test volumio[2601]: info: Creating Spotify config file Jan 12 08:44:53 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 08:44:53 volumio-test systemd[1]: mpd.service: Deactivated successfully. Jan 12 08:44:53 volumio-test systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 12 08:44:53 volumio-test systemd[1]: mpd.service: Consumed 9.014s CPU time. Jan 12 08:44:53 volumio-test systemd[1]: mpd.socket: Deactivated successfully. Jan 12 08:44:53 volumio-test systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 12 08:44:53 volumio-test systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 12 08:44:53 volumio-test systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 12 08:44:53 volumio-test systemd[1]: Starting mpd.service - Music Player Daemon... Jan 12 08:44:53 volumio-test volumio[2601]: info: AutoStart - onStart Jan 12 08:44:53 volumio-test volumio[2601]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 12 08:44:53 volumio-test volumio[2601]: info: [1768232693494] CoreMusicLibrary::Adding element Pandora Radio Jan 12 08:44:53 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 12 08:44:53 volumio-test volumio[2601]: Cannot find translation for source Pandora Radio Jan 12 08:44:53 volumio-test volumio[2601]: info: [1768232693499] ControllerPandora::initialSetup Jan 12 08:44:53 volumio-test volumio[2601]: info: [1768232693502] ControllerPandora::checkPing Jan 12 08:44:53 volumio-test volumio[2601]: info: Volumio Calling Home Jan 12 08:44:53 volumio-test sudo[2765]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 12 08:44:53 volumio-test sudo[2765]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 12 08:44:53 volumio-test sudo[2765]: pam_unix(sudo:session): session closed for user root Jan 12 08:44:53 volumio-test volumio[2601]: info: Discovery: adding 58674b00-fea4-48a1-9f1b-3574d6b4de18 Jan 12 08:44:53 volumio-test volumio[2601]: info: Discovery: Found device Global Player 2 Jan 12 08:44:53 volumio-test volumio[2601]: info: Discovery: Connecting to remote: 192.168.1.198 Jan 12 08:44:53 volumio-test volumio[2601]: info: Discovery: adding e84cfa8f-4c36-4bfe-93ae-13fea8e6f1b7 Jan 12 08:44:53 volumio-test volumio[2601]: info: Discovery: Found device Volumio Test Jan 12 08:44:53 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:53 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:53 volumio-test volumio[2601]: verbose: New Socket.io Connection to 192.168.1.139 from 192.168.1.64 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Jan 12 08:44:53 volumio-test volumio[2601]: verbose: New Socket.io Connection to 192.168.1.139 from 192.168.1.64 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Jan 12 08:44:53 volumio-test volumio[2601]: info: MPD Permissions set Jan 12 08:44:53 volumio-test volumio[2601]: info: MPD Permissions set Jan 12 08:44:53 volumio-test volumio[2601]: info: Discovery: this is already registered, e84cfa8f-4c36-4bfe-93ae-13fea8e6f1b7 Jan 12 08:44:53 volumio-test volumio[2601]: info: Discovery: Found device Volumio Test Jan 12 08:44:53 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:53 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:53 volumio-test volumio[2601]: verbose: New Socket.io Connection to 192.168.1.139:3000 from 192.168.1.198 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jan 12 08:44:53 volumio-test volumio[2601]: info: Spotify config file written Jan 12 08:44:53 volumio-test sudo[2773]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 12 08:44:53 volumio-test sudo[2773]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 08:44:54 volumio-test systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 12 08:44:54 volumio-test systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 12 08:44:54 volumio-test systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 12 08:44:54 volumio-test volumio[2601]: info: Volumio called home Jan 12 08:44:54 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 08:44:54 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 08:44:54 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 08:44:54 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 08:44:54 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 08:44:54 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 08:44:54 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 08:44:54 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 08:44:54 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 08:44:54 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 08:44:54 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 08:44:54 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 08:44:54 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 08:44:54 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 08:44:54 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 08:44:54 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 08:44:54 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 08:44:54 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 08:44:54 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 08:44:54 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 08:44:54 volumio-test volumio[2601]: info: No need to fix Spotify hosts Jan 12 08:44:54 volumio-test go-librespot[2775]: go-librespot daemon starting... Jan 12 08:44:54 volumio-test systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 12 08:44:54 volumio-test sudo[2773]: pam_unix(sudo:session): session closed for user root Jan 12 08:44:54 volumio-test go-librespot[2787]: time="2026-01-12T08:44:54-07:00" level=info msg="running go-librespot 0.4.0" Jan 12 08:44:54 volumio-test go-librespot[2787]: time="2026-01-12T08:44:54-07:00" level=debug msg="app state loaded" Jan 12 08:44:54 volumio-test go-librespot[2787]: time="2026-01-12T08:44:54-07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 12 08:44:54 volumio-test volumio[2601]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jan 12 08:44:54 volumio-test volumio[2601]: info: Discovery: Connected to remote: 192.168.1.198 Jan 12 08:44:54 volumio-test volumio[2601]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 12 08:44:54 volumio-test volumio[2601]: SPOTIFY: BQDAWjo6Qfe-EBE4U61-XvtvibkLFXmnqzNCMDXIqWc4jccsBhfXLifYSHHAxf9ebqutt-VwV0gbSsLsRPvXD-ZHPYYAZosVZ1ew7M_dSzlboTkaPoTOhXgvmpS1tsFt5KvJ4-TrlhF7JsRljbCS70-lM-E8Tsg8bq0-R-5LUKPhcsw8oSPRFidfmdvSWP5JVvMZK0J_OmKvEXXOQms9QP0dPed7maabAkwIi_9Kpv3p4g3TvxZogyhgWNuzXo6JkhlG-Zvag19qyCpT5T-uOAUL1FrXV7t5iZKJfL79Mg Jan 12 08:44:54 volumio-test volumio[2601]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 12 08:44:54 volumio-test volumio[2601]: info: New Spotify access token = BQDAWjo6Qfe-EBE4U61-XvtvibkLFXmnqzNCMDXIqWc4jccsBhfXLifYSHHAxf9ebqutt-VwV0gbSsLsRPvXD-ZHPYYAZosVZ1ew7M_dSzlboTkaPoTOhXgvmpS1tsFt5KvJ4-TrlhF7JsRljbCS70-lM-E8Tsg8bq0-R-5LUKPhcsw8oSPRFidfmdvSWP5JVvMZK0J_OmKvEXXOQms9QP0dPed7maabAkwIi_9Kpv3p4g3TvxZogyhgWNuzXo6JkhlG-Zvag19qyCpT5T-uOAUL1FrXV7t5iZKJfL79Mg Jan 12 08:44:54 volumio-test volumio[2601]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 12 08:44:54 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 12 08:44:54 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:54 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:54 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetVisibleSources Jan 12 08:44:54 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 12 08:44:54 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:44:54 volumio-test volumio[2601]: info: CoreStateMachine::getQueue Jan 12 08:44:54 volumio-test volumio[2601]: info: CorePlayQueue::getQueue Jan 12 08:44:54 volumio-test volumio[2601]: info: Listing playlists Jan 12 08:44:54 volumio-test go-librespot[2787]: time="2026-01-12T08:44:54-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 12 08:44:54 volumio-test go-librespot[2787]: time="2026-01-12T08:44:54-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 12 08:44:54 volumio-test go-librespot[2787]: time="2026-01-12T08:44:54-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 12 08:44:54 volumio-test go-librespot[2787]: time="2026-01-12T08:44:54-07:00" level=info msg="zeroconf server listening on port 43365" Jan 12 08:44:54 volumio-test go-librespot[2787]: time="2026-01-12T08:44:54-07:00" level=debug msg="obtained new client token: AAC7tViowJGHXTRdMggXeLLlS9Nk1PkxQznFcwJniav+zu35HG8nasJ84So5kYWifk8Ls+b7zEZBJhsWy/XN8SiUqN/O6Lg4cDhPLVt6vZFd2f26L/iFASbBq92aIDu7tdY2BLMozq/5Va030jbVBPd+3LhOSmZ5KuEgl+aNHQjI5ut1M2I9ntA3eV2gEWg7p7EmDDLfh8JTRzi1tRNbpPm7m7l1nsqKTJUFSBQSECl3uac2/dG9cUX824Bm" Jan 12 08:44:54 volumio-test volumio[2601]: verbose: New Socket.io Connection to 192.168.1.139:3000 from 192.168.1.198 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jan 12 08:44:55 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:55 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:55 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:44:55 volumio-test volumio[2601]: info: CoreStateMachine::getQueue Jan 12 08:44:55 volumio-test volumio[2601]: info: CorePlayQueue::getQueue Jan 12 08:44:55 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Jan 12 08:44:55 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:55 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:55 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:55 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:55 volumio-test volumio[2601]: SPOTIFY: User informations: {"country":"US","display_name":"Keith Erbe","email":"cratermaker@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/cratermaker-us"},"followers":{"href":null,"total":4},"href":"https://api.spotify.com/v1/users/cratermaker-us","id":"cratermaker-us","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee8588f14251c9c92ed07bc40663","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b8288f14251c9c92ed07bc40663","width":64}],"product":"premium","type":"user","uri":"spotify:user:cratermaker-us"} Jan 12 08:44:55 volumio-test volumio[2601]: info: Spotify Successfully logged in Jan 12 08:44:55 volumio-test volumio[2601]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 12 08:44:55 volumio-test volumio[2601]: info: [1768232695925] CoreMusicLibrary::Adding element Spotify Jan 12 08:44:55 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 12 08:44:55 volumio-test volumio[2601]: Cannot find translation for source Pandora Radio Jan 12 08:44:55 volumio-test volumio[2601]: Cannot find translation for source Spotify Jan 12 08:44:56 volumio-test sudo[2818]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 12 08:44:56 volumio-test sudo[2818]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 08:44:56 volumio-test sudo[2818]: pam_unix(sudo:session): session closed for user root Jan 12 08:44:56 volumio-test sudo[2820]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 12 08:44:56 volumio-test sudo[2820]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 08:44:56 volumio-test sudo[2820]: pam_unix(sudo:session): session closed for user root Jan 12 08:44:56 volumio-test volumio[2601]: verbose: New Socket.io Connection to 192.168.1.139 from 192.168.1.64 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Jan 12 08:44:56 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetVisibleSources Jan 12 08:44:56 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 12 08:44:56 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:56 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:56 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:44:56 volumio-test volumio[2601]: info: CoreStateMachine::getQueue Jan 12 08:44:56 volumio-test volumio[2601]: info: CorePlayQueue::getQueue Jan 12 08:44:56 volumio-test volumio[2601]: info: Listing playlists Jan 12 08:44:56 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 12 08:44:56 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 12 08:44:56 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 12 08:44:56 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 12 08:44:56 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 12 08:44:56 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:56 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:56 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:44:56 volumio-test volumio[2601]: info: CoreStateMachine::getQueue Jan 12 08:44:56 volumio-test volumio[2601]: info: CorePlayQueue::getQueue Jan 12 08:44:56 volumio-test mpd[2770]: 2026-01-12T08:44:56 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 12 08:44:56 volumio-test systemd[1]: Started mpd.service - Music Player Daemon. Jan 12 08:44:56 volumio-test sudo[2742]: pam_unix(sudo:session): session closed for user root Jan 12 08:44:56 volumio-test sudo[2748]: pam_unix(sudo:session): session closed for user root Jan 12 08:44:57 volumio-test volumio[2601]: error: MPD error: The expression evaluated to a falsy value: Jan 12 08:44:57 volumio-test volumio[2601]: assert.ok(self.idling) Jan 12 08:44:57 volumio-test volumio[2601]: error: The expression evaluated to a falsy value: Jan 12 08:44:57 volumio-test volumio[2601]: assert.ok(self.idling) Jan 12 08:44:57 volumio-test volumio[2601]: info: MPD running with PID2770 Jan 12 08:44:57 volumio-test volumio[2601]: ,establishing connection Jan 12 08:44:57 volumio-test volumio[2601]: error: updateQueue error: null Jan 12 08:44:57 volumio-test volumio[2601]: error: updateQueue error: null Jan 12 08:44:57 volumio-test volumio[2601]: info: go-librespot daemon successfully initialized Jan 12 08:44:57 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Jan 12 08:44:57 volumio-test volumio[2601]: info: Preload queue cleared Jan 12 08:44:57 volumio-test volumio-remote-updater[686]: [2026-01-12 08:44:57] [connect] Successful connection Jan 12 08:44:57 volumio-test volumio-remote-updater[686]: [2026-01-12 08:44:57] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1768232697 101 Jan 12 08:44:57 volumio-test volumio[2601]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 9 Jan 12 08:44:58 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:58 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:58 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:44:58 volumio-test volumio[2601]: info: CoreStateMachine::getQueue Jan 12 08:44:58 volumio-test volumio[2601]: info: CorePlayQueue::getQueue Jan 12 08:44:58 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 12 08:44:58 volumio-test volumio[2601]: info: Received Get System Info Jan 12 08:44:58 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 12 08:44:58 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 12 08:44:58 volumio-test volumio[2601]: info: Discovery: Getting this device information Jan 12 08:44:58 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:58 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:58 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 12 08:44:58 volumio-test volumio[2601]: info: [1768232698554] [Pandora] checkPing: ***LOOKS GOOD, ICE DOWN THE BEERS IN THE COOLER*** Jan 12 08:44:58 volumio-test volumio[2601]: info: [1768232698555] ControllerPandora::checkHTTP Jan 12 08:44:58 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 12 08:44:58 volumio-test volumio[2601]: info: Received Get System Info Jan 12 08:44:58 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 12 08:44:58 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 12 08:44:58 volumio-test volumio[2601]: info: Discovery: Getting this device information Jan 12 08:44:58 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:44:58 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:44:58 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 12 08:44:59 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Jan 12 08:44:59 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Jan 12 08:44:59 volumio-test sudo[2831]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 12 08:44:59 volumio-test sudo[2831]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 08:44:59 volumio-test sudo[2833]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 12 08:44:59 volumio-test sudo[2833]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 08:44:59 volumio-test systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 12 08:45:00 volumio-test systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 12 08:45:00 volumio-test systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 12 08:45:00 volumio-test systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 12 08:45:00 volumio-test sudo[2831]: pam_unix(sudo:session): session closed for user root Jan 12 08:45:00 volumio-test sudo[2833]: pam_unix(sudo:session): session closed for user root Jan 12 08:45:00 volumio-test volumio[2601]: info: Successfully started MPD Monitor Jan 12 08:45:00 volumio-test mpd_monitor.sh[2836]: MPD Monitor Service: Starting MPD Monitor Service Jan 12 08:45:00 volumio-test volumio[2601]: info: Successfully started MPD Monitor Jan 12 08:45:00 volumio-test volumio[2601]: info: Initializing connection to go-librespot Websocket Jan 12 08:45:00 volumio-test go-librespot[2787]: time="2026-01-12T08:45:00-07:00" level=debug msg="new websocket client" Jan 12 08:45:00 volumio-test volumio[2601]: info: Connection to go-librespot Websocket established Jan 12 08:45:00 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:45:00 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:45:00 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:45:00 volumio-test volumio[2601]: info: CoreStateMachine::getQueue Jan 12 08:45:00 volumio-test volumio[2601]: info: CorePlayQueue::getQueue Jan 12 08:45:01 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Jan 12 08:45:01 volumio-test volumio[2601]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 12 08:45:02 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:45:02 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:45:02 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:45:02 volumio-test volumio[2601]: info: CoreStateMachine::getQueue Jan 12 08:45:02 volumio-test volumio[2601]: info: CorePlayQueue::getQueue Jan 12 08:45:03 volumio-test volumio[2601]: info: Getting Spotify volume Jan 12 08:45:03 volumio-test volumio[2601]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Jan 12 08:45:03 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:45:03 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:45:03 volumio-test volumio[2601]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Jan 12 08:45:03 volumio-test volumio[2601]: SPOTIFY: SPOTIFY VOLUME undefined Jan 12 08:45:03 volumio-test volumio[2601]: SPOTIFY: VOLUMIO VOLUME 35 Jan 12 08:45:03 volumio-test volumio[2601]: info: Aligning Spotify Volume to Volumio Volume Jan 12 08:45:03 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:45:03 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:45:03 volumio-test volumio[2601]: info: Setting Spotify Volume from Volumio: 35 Jan 12 08:45:03 volumio-test volumio[2601]: info: [1768232703837] [Pandora] checkHTTP: ***CRACK THE BEERS WE HAVE INTERNET*** Jan 12 08:45:03 volumio-test volumio[2601]: info: [1768232703838] ControllerPandora::initializeMQTT Jan 12 08:45:03 volumio-test volumio[2601]: info: [1768232703839] [Pandora] initializeMQTT: MQTT is not enabled in Plugin Configuration Jan 12 08:45:03 volumio-test volumio[2601]: info: [1768232703839] ControllerPandora::PandoraHandler::init Jan 12 08:45:03 volumio-test volumio[2601]: info: [1768232703840] ControllerPandora::PandoraHandler::loadErrorCodes Jan 12 08:45:03 volumio-test volumio[2601]: info: [1768232703843] ControllerPandora::validateAndSetAccountOptions Jan 12 08:45:03 volumio-test volumio[2601]: info: [1768232703845] ControllerPandora::PandoraHandler::setAccountOptions Jan 12 08:45:03 volumio-test volumio[2601]: info: [1768232703847] ControllerPandora::flushPandora Jan 12 08:45:03 volumio-test volumio[2601]: info: CorePlayQueue::getQueue Jan 12 08:45:03 volumio-test volumio[2601]: info: CorePlayQueue::clearPlayQueue Jan 12 08:45:03 volumio-test volumio[2601]: info: CorePlayQueue::saveQueue Jan 12 08:45:03 volumio-test volumio[2601]: info: CoreCommandRouter::volumioPushQueue Jan 12 08:45:03 volumio-test volumio[2601]: info: [1768232703861] [Pandora] PreventAuthTimeout::init: Timer loaded Jan 12 08:45:03 volumio-test volumio[2601]: info: [1768232703862] [Pandora] PreventAuthTimeout::init: Interval set to 10800000 ms Jan 12 08:45:03 volumio-test volumio[2601]: info: [1768232703862] [Pandora] PreventAuthTimeout::init: Starting delayed timer after next interval Jan 12 08:45:03 volumio-test volumio[2601]: info: [1768232703863] ControllerPandora::PandoraHandler::pandoraLoginAndGetStations Jan 12 08:45:04 volumio-test volumio[2601]: info: [1768232704347] [Pandora] PandoraHandler::pandoraLoginAndGetStations::pandoraLogin: [<=- Logged in to Pandora Servers -=>] Jan 12 08:45:04 volumio-test volumio[2601]: info: [1768232704356] [Pandora] validateAndSetAccountOptions: ***DEBUG*** self.loggedIn: true Jan 12 08:45:04 volumio-test volumio[2601]: info: [1768232704358] [Pandora] ExpireOldTracks::init: Timer loaded Jan 12 08:45:04 volumio-test volumio[2601]: info: [1768232704359] [Pandora] ExpireOldTracks::init: Interval set to 300000 ms Jan 12 08:45:04 volumio-test volumio[2601]: info: [1768232704360] [Pandora] ExpireOldTracks::init: Starting delayed timer after next interval Jan 12 08:45:04 volumio-test volumio[2601]: info: [1768232704361] ControllerPandora::PandoraHandler::fillStationData Jan 12 08:45:04 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:45:04 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:45:04 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:45:04 volumio-test volumio[2601]: info: CoreStateMachine::getQueue Jan 12 08:45:04 volumio-test volumio[2601]: info: CorePlayQueue::getQueue Jan 12 08:45:04 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Jan 12 08:45:04 volumio-test volumio[2601]: info: [1768232704679] [Pandora] PandoraHandler::setMaxStationTracks: 16 Jan 12 08:45:04 volumio-test volumio[2601]: info: [1768232704680] [Pandora] PandoraHandler::setBandFilter: bandfilter is empty Jan 12 08:45:04 volumio-test volumio[2601]: info: [1768232704681] ControllerPandora::flushPandora Jan 12 08:45:04 volumio-test volumio[2601]: info: CorePlayQueue::getQueue Jan 12 08:45:04 volumio-test volumio[2601]: info: CorePlayQueue::clearPlayQueue Jan 12 08:45:04 volumio-test volumio[2601]: info: CorePlayQueue::saveQueue Jan 12 08:45:04 volumio-test volumio[2601]: info: CoreCommandRouter::volumioPushQueue Jan 12 08:45:04 volumio-test volumio[2601]: info: Completed starting Core Plugins Jan 12 08:45:04 volumio-test volumio[2601]: info: ------------------------------------------- Jan 12 08:45:04 volumio-test volumio[2601]: info: ----- MyVolumio plugins startup ---- Jan 12 08:45:04 volumio-test volumio[2601]: info: ------------------------------------------- Jan 12 08:45:04 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 12 08:45:04 volumio-test volumio[2601]: SPOTIFY: SETTING SPOTIFY VOLUME 35 Jan 12 08:45:04 volumio-test volumio[2601]: info: Sending Spotify command with payload to local API: /player/volume Jan 12 08:45:05 volumio-test systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 11108. Jan 12 08:45:05 volumio-test systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Jan 12 08:45:05 volumio-test systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jan 12 08:45:06 volumio-test upmpdcli[2855]: Could not open config: /tmp/upmpdcli.conf Jan 12 08:45:06 volumio-test systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jan 12 08:45:06 volumio-test systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jan 12 08:45:06 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:45:06 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:45:06 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:45:06 volumio-test volumio[2601]: info: CoreStateMachine::getQueue Jan 12 08:45:06 volumio-test volumio[2601]: info: CorePlayQueue::getQueue Jan 12 08:45:08 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:45:08 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:45:08 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:45:08 volumio-test volumio[2601]: info: CoreStateMachine::getQueue Jan 12 08:45:08 volumio-test volumio[2601]: info: CorePlayQueue::getQueue Jan 12 08:45:10 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:45:10 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:45:10 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:45:10 volumio-test volumio[2601]: info: CoreStateMachine::getQueue Jan 12 08:45:10 volumio-test volumio[2601]: info: CorePlayQueue::getQueue Jan 12 08:45:12 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:45:12 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:45:12 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:45:12 volumio-test volumio[2601]: info: CoreStateMachine::getQueue Jan 12 08:45:12 volumio-test volumio[2601]: info: CorePlayQueue::getQueue Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 12 08:45:13 volumio-test volumio[2601]: info: Adding plugin bluetooth to MyMusic Plugins Jan 12 08:45:13 volumio-test volumio[2601]: info: Adding plugin multiroom to MyMusic Plugins Jan 12 08:45:13 volumio-test volumio[2601]: info: Adding plugin metavolumio to MyMusic Plugins Jan 12 08:45:13 volumio-test volumio[2601]: info: Adding plugin cd_controller to MyMusic Plugins Jan 12 08:45:13 volumio-test volumio[2601]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 12 08:45:13 volumio-test volumio[2601]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 12 08:45:13 volumio-test volumio[2601]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 12 08:45:13 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 12 08:45:14 volumio-test volumio[2601]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 12 08:45:14 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 12 08:45:14 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 08:45:14 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 08:45:14 volumio-test volumio[2601]: info: Starting MyVolumio Remote Streaming Endpoints Jan 12 08:45:14 volumio-test volumio[2601]: info: MyVolumio login type: Token Jan 12 08:45:14 volumio-test volumio[2601]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 12 08:45:14 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 12 08:45:15 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 12 08:45:15 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 12 08:45:15 volumio-test volumio[2601]: info: Streaming services startup Jan 12 08:45:15 volumio-test volumio[2601]: info: Starting Streaming Daemon Jan 12 08:45:15 volumio-test sudo[2857]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 12 08:45:15 volumio-test sudo[2857]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 08:45:15 volumio-test volumio[2601]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 12 08:45:15 volumio-test sudo[2857]: pam_unix(sudo:session): session closed for user root Jan 12 08:45:15 volumio-test volumio[2601]: info: AutoStart - Plugin is starting Jan 12 08:45:15 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:45:15 volumio-test volumio[2601]: info: CoreStateMachine::getQueue Jan 12 08:45:15 volumio-test volumio[2601]: info: CorePlayQueue::getQueue Jan 12 08:45:15 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 12 08:45:15 volumio-test volumio[2601]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jan 12 08:45:15 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jan 12 08:45:15 volumio-test volumio[2601]: info: Received Get System Version Jan 12 08:45:15 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 12 08:45:15 volumio-test volumio[2601]: info: Received Get System Info Jan 12 08:45:15 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 12 08:45:15 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 12 08:45:15 volumio-test volumio[2601]: info: Discovery: Getting this device information Jan 12 08:45:15 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:45:15 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:45:15 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 12 08:45:15 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Jan 12 08:45:15 volumio-test volumio[2601]: info: TuneIn handleBrowseUri: tunein/popular Jan 12 08:45:15 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:45:15 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:45:15 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:45:15 volumio-test volumio[2601]: info: CoreStateMachine::getQueue Jan 12 08:45:15 volumio-test volumio[2601]: info: CorePlayQueue::getQueue Jan 12 08:45:15 volumio-test volumio[2601]: error: Cannot start Volumio Streaming Daemon Jan 12 08:45:15 volumio-test volumio[2601]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 12 08:45:15 volumio-test volumio[2601]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 12 08:45:15 volumio-test volumio[2601]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 12 08:45:16 volumio-test volumio[2601]: info: MyVolumio token set successfully Jan 12 08:45:16 volumio-test volumio[2601]: info: MYVOLUMIO: Adding device Jan 12 08:45:16 volumio-test volumio[2601]: info: MYVOLUMIO: Evaluating Server Jan 12 08:45:16 volumio-test volumio[2601]: info: MyVolumio status changed Jan 12 08:45:16 volumio-test volumio[2601]: info: Streaming services startup Jan 12 08:45:16 volumio-test volumio[2601]: info: Starting Streaming Daemon Jan 12 08:45:16 volumio-test volumio[2601]: info: Removing browser output: myVolumio user plan is not superstar Jan 12 08:45:16 volumio-test volumio[2601]: info: Removing audio output: Jan 12 08:45:16 volumio-test volumio[2601]: info: Stoppping Tunnel 1 Jan 12 08:45:16 volumio-test sudo[2898]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 12 08:45:16 volumio-test sudo[2898]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 08:45:16 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Jan 12 08:45:16 volumio-test volumio[2601]: info: TuneIn handleBrowseUri: tunein/popular Jan 12 08:45:16 volumio-test sudo[2900]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 12 08:45:16 volumio-test sudo[2900]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 08:45:16 volumio-test systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 12 08:45:16 volumio-test systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 12 08:45:16 volumio-test sudo[2898]: pam_unix(sudo:session): session closed for user root Jan 12 08:45:16 volumio-test volumio[2601]: error: Cannot start Volumio Streaming Daemon Jan 12 08:45:16 volumio-test volumio[2601]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 12 08:45:16 volumio-test volumio[2601]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 12 08:45:16 volumio-test systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 12 08:45:16 volumio-test systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 12 08:45:16 volumio-test systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 12 08:45:16 volumio-test systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 12 08:45:16 volumio-test systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 12 08:45:16 volumio-test systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 12 08:45:16 volumio-test sudo[2900]: pam_unix(sudo:session): session closed for user root Jan 12 08:45:16 volumio-test volumio[2601]: info: Remote SSH Stopped Jan 12 08:45:16 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:45:16 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:45:16 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:45:16 volumio-test volumio[2601]: info: CoreStateMachine::getQueue Jan 12 08:45:16 volumio-test volumio[2601]: info: CorePlayQueue::getQueue Jan 12 08:45:18 volumio-test volumio[2601]: info: Setting Geolocation for MyVolumio to us2 Jan 12 08:45:18 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 08:45:18 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 08:45:18 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 08:45:18 volumio-test volumio[2601]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 12 08:45:18 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:45:18 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:45:18 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:45:18 volumio-test volumio[2601]: info: CoreStateMachine::getQueue Jan 12 08:45:18 volumio-test volumio[2601]: info: CorePlayQueue::getQueue Jan 12 08:45:19 volumio-test volumio[2601]: info: Updating MyVolumio device info Jan 12 08:45:19 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 08:45:19 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 08:45:19 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 08:45:19 volumio-test volumio[2601]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 12 08:45:20 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:45:20 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:45:20 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:45:20 volumio-test volumio[2601]: info: CoreStateMachine::getQueue Jan 12 08:45:20 volumio-test volumio[2601]: info: CorePlayQueue::getQueue Jan 12 08:45:21 volumio-test systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 11109. Jan 12 08:45:21 volumio-test systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Jan 12 08:45:21 volumio-test systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Jan 12 08:45:21 volumio-test upmpdcli[2907]: Could not open config: /tmp/upmpdcli.conf Jan 12 08:45:21 volumio-test systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Jan 12 08:45:21 volumio-test systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Jan 12 08:45:22 volumio-test volumio[2601]: info: MYVOLUMIO: Adding device Jan 12 08:45:22 volumio-test volumio[2601]: info: MYVOLUMIO: Evaluating Server Jan 12 08:45:22 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:45:22 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:45:22 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:45:22 volumio-test volumio[2601]: info: CoreStateMachine::getQueue Jan 12 08:45:22 volumio-test volumio[2601]: info: CorePlayQueue::getQueue Jan 12 08:45:23 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 12 08:45:23 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 08:45:23 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 12 08:45:23 volumio-test volumio-remote-updater[686]: Test mode disabled Jan 12 08:45:23 volumio-test volumio-remote-updater[686]: Alpha mode disabled Jan 12 08:45:23 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jan 12 08:45:23 volumio-test volumio-remote-updater[686]: Alpha legacy test mode disabled Jan 12 08:45:23 volumio-test volumio[2601]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Jan 12 08:45:23 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jan 12 08:45:24 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetState Jan 12 08:45:24 volumio-test volumio[2601]: info: CorePlayQueue::getTrack 0 Jan 12 08:45:24 volumio-test volumio[2601]: info: CoreCommandRouter::volumioGetQueue Jan 12 08:45:24 volumio-test volumio[2601]: info: CoreStateMachine::getQueue Jan 12 08:45:24 volumio-test volumio[2601]: info: CorePlayQueue::getQueue Jan 12 08:45:24 volumio-test volumio[2601]: info: Setting Geolocation for MyVolumio to us2 Jan 12 08:45:24 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 08:45:24 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 08:45:24 volumio-test volumio[2601]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 08:45:24 volumio-test go-librespot[2787]: time="2026-01-12T08:45:24-07:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: i/o timeout" Jan 12 08:45:24 volumio-test go-librespot[2787]: time="2026-01-12T08:45:24-07:00" level=debug msg="connected to ap-guc3.spotify.com:443" Jan 12 08:45:24 volumio-test volumio[2601]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 12 08:45:24 volumio-test go-librespot[2787]: time="2026-01-12T08:45:24-07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.139:44140->104.154.127.247:443: read: connection reset by peer" Jan 12 08:45:24 volumio-test systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 12 08:45:24 volumio-test systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 12 08:45:24 volumio-test volumio[2601]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Jan 12 08:45:24 volumio-test volumio[2601]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 12 08:45:24 volumio-test volumio[2601]: Error: socket hang up Jan 12 08:45:24 volumio-test volumio[2601]: at connResetException (node:internal/errors:720:14) Jan 12 08:45:24 volumio-test volumio[2601]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 12 08:45:24 volumio-test volumio[2601]: at Socket.emit (node:events:526:35) Jan 12 08:45:24 volumio-test volumio[2601]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 12 08:45:24 volumio-test volumio[2601]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 12 08:45:24 volumio-test volumio[2601]: code: 'ECONNRESET', Jan 12 08:45:24 volumio-test volumio[2601]: response: undefined Jan 12 08:45:24 volumio-test volumio[2601]: } Jan 12 08:45:24 volumio-test volumio[2601]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 12 08:45:25 volumio-test sudo[2958]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-12 08:44' Jan 12 08:45:25 volumio-test sudo[2958]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"