Apr 03 14:39:00 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:00 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:00 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:00 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:01 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:01 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:01 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:01 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:02 main-office-tester systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 5661. Apr 03 14:39:02 main-office-tester systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Apr 03 14:39:02 main-office-tester systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Apr 03 14:39:02 main-office-tester upmpdcli[7757]: Could not open config: /tmp/upmpdcli.conf Apr 03 14:39:02 main-office-tester systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Apr 03 14:39:02 main-office-tester systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Apr 03 14:39:02 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:02 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:02 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:02 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:03 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:03 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:03 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:03 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:04 main-office-tester volumio[1107]: info: Apr 03 14:39:04 main-office-tester volumio[1107]: ---------------------------- Client requests Volumio next Apr 03 14:39:04 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioNext Apr 03 14:39:04 main-office-tester volumio[1107]: info: CoreStateMachine::next Apr 03 14:39:04 main-office-tester volumio[1107]: info: [1775252344206] ControllerPandora::next Apr 03 14:39:04 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:04 main-office-tester volumio[1107]: info: [1775252344207] [Pandora] handleMediaButton: User chose "next" function Apr 03 14:39:04 main-office-tester volumio[1107]: info: [1775252344208] ControllerPandora::clearAddPlayTrack Apr 03 14:39:04 main-office-tester volumio[1107]: info: ControllerMpd::clear Apr 03 14:39:04 main-office-tester volumio[1107]: verbose: ControllerMpd::sendMpdCommand clear Apr 03 14:39:04 main-office-tester mpd[1369]: player: played "http://t1-1.p-cdn.us/access/847199291277820509.mp3?version=5&lid=172328487&token=HRjPuwetOL4zk%2BNTA6tKDRpRIDiVgSpq%2FsnJg%2BdSQsafqz2Yepbl122WtSsS4c%2Fl2cd1CWkvLfrD4om26E8zy97W2JJV2X9TxHOXx4IT1MQZinHxrahVNgh3NRIkLrCm2nlhbthrGmmTU3FgOtrisp4VAu%2FbhL4IK1VezQiN%2F90XQmJfZEbDh4c4qjs9mCQ9OFRYyPvhjGGKM04orW7rmfI%2Fl2kdHixVhkzKu7GGHnRyWEjM0FZH8Ml8RXeAMQqKERJlK5%2F39c3IMfIYyP6wVJfHPo%2FbKy%2BMR6fnbMA%2F%2FcHKz0%2Fu5E9xTex2GiDNwoltjKhxqmR6oAcH2FGBwEjkeQ%3D%3D" Apr 03 14:39:04 main-office-tester volumio[1107]: info: Apr 03 14:39:04 main-office-tester volumio[1107]: ---------------------------- MPD announces system playlist update Apr 03 14:39:04 main-office-tester volumio[1107]: info: Ignoring MPD Status Update Apr 03 14:39:04 main-office-tester volumio[1107]: info: Apr 03 14:39:04 main-office-tester volumio[1107]: ---------------------------- MPD announces state update: player Apr 03 14:39:04 main-office-tester volumio[1107]: info: sendMpdCommand clear took 92 milliseconds Apr 03 14:39:04 main-office-tester volumio[1107]: info: ControllerMpd::getState Apr 03 14:39:04 main-office-tester volumio[1107]: verbose: ControllerMpd::sendMpdCommand status Apr 03 14:39:04 main-office-tester volumio[1107]: info: [1775252344302] ControllerPandora::checkForExpiredStations Apr 03 14:39:04 main-office-tester volumio[1107]: error: [1775252344303] [Pandora] clearAddPlayTrack: Error: TypeError: Cannot read properties of undefined (reading 'uri') Apr 03 14:39:04 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:04 main-office-tester volumio[1107]: info: [1775252344304] [Pandora] handleMediaButton: Media track skipped in less than 250ms. Apr 03 14:39:04 main-office-tester volumio[1107]: info: [1775252344304] [Pandora] handleMediaButton: User chose "spaz" function Apr 03 14:39:04 main-office-tester volumio[1107]: info: Apr 03 14:39:04 main-office-tester volumio[1107]: ---------------------------- MPD announces system playlist update Apr 03 14:39:04 main-office-tester volumio[1107]: info: Ignoring MPD Status Update Apr 03 14:39:04 main-office-tester volumio[1107]: info: Apr 03 14:39:04 main-office-tester volumio[1107]: ---------------------------- MPD announces state update: player Apr 03 14:39:04 main-office-tester volumio[1107]: info: ControllerMpd::getState Apr 03 14:39:04 main-office-tester volumio[1107]: verbose: ControllerMpd::sendMpdCommand status Apr 03 14:39:04 main-office-tester volumio[1107]: info: Apr 03 14:39:04 main-office-tester volumio[1107]: ---------------------------- MPD announces system playlist update Apr 03 14:39:04 main-office-tester volumio[1107]: info: Ignoring MPD Status Update Apr 03 14:39:04 main-office-tester volumio[1107]: info: Apr 03 14:39:04 main-office-tester volumio[1107]: ---------------------------- MPD announces state update: player Apr 03 14:39:04 main-office-tester volumio[1107]: info: ControllerMpd::getState Apr 03 14:39:04 main-office-tester volumio[1107]: verbose: ControllerMpd::sendMpdCommand status Apr 03 14:39:04 main-office-tester volumio[1107]: error: updateQueue error: null Apr 03 14:39:04 main-office-tester volumio[1107]: error: updateQueue error: null Apr 03 14:39:04 main-office-tester volumio[1107]: error: updateQueue error: null Apr 03 14:39:04 main-office-tester volumio[1107]: info: ------------------------------ 10ms Apr 03 14:39:04 main-office-tester volumio[1107]: info: sendMpdCommand status took 9 milliseconds Apr 03 14:39:04 main-office-tester volumio[1107]: info: ------------------------------ 6ms Apr 03 14:39:04 main-office-tester volumio[1107]: info: sendMpdCommand status took 5 milliseconds Apr 03 14:39:04 main-office-tester volumio[1107]: info: ------------------------------ 4ms Apr 03 14:39:04 main-office-tester volumio[1107]: info: sendMpdCommand status took 4 milliseconds Apr 03 14:39:04 main-office-tester volumio[1107]: verbose: ControllerMpd::parseState Apr 03 14:39:04 main-office-tester volumio[1107]: verbose: ControllerMpd::parseState Apr 03 14:39:04 main-office-tester volumio[1107]: verbose: ControllerMpd::parseState Apr 03 14:39:04 main-office-tester volumio[1107]: info: ControllerMpd::pushState Apr 03 14:39:04 main-office-tester volumio[1107]: info: CoreCommandRouter::servicePushState Apr 03 14:39:04 main-office-tester volumio[1107]: info: CoreStateMachine::pushState Apr 03 14:39:04 main-office-tester volumio[1107]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 14:39:04 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioPushState Apr 03 14:39:04 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 170 Apr 03 14:39:04 main-office-tester volumio[1107]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 14:39:04 main-office-tester volumio[1107]: verbose: CURRENT POSITION 170 Apr 03 14:39:04 main-office-tester volumio[1107]: info: CoreStateMachine::syncState stateService stop Apr 03 14:39:04 main-office-tester volumio[1107]: info: CoreStateMachine::syncState currentStatus play Apr 03 14:39:04 main-office-tester volumio[1107]: info: CoreStateMachine::play index undefined Apr 03 14:39:04 main-office-tester volumio[1107]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 14:39:04 main-office-tester volumio[1107]: info: CoreStateMachine::pushState Apr 03 14:39:04 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:04 main-office-tester volumio[1107]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 14:39:04 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioPushState Apr 03 14:39:04 main-office-tester volumio[1107]: info: ControllerMpd::pushState Apr 03 14:39:04 main-office-tester volumio[1107]: info: CoreCommandRouter::servicePushState Apr 03 14:39:04 main-office-tester volumio[1107]: info: CoreStateMachine::pushState Apr 03 14:39:04 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:04 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioPushState Apr 03 14:39:04 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:04 main-office-tester volumio[1107]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Apr 03 14:39:04 main-office-tester volumio[1107]: info: ControllerMpd::pushState Apr 03 14:39:04 main-office-tester volumio[1107]: info: CoreCommandRouter::servicePushState Apr 03 14:39:04 main-office-tester volumio[1107]: info: CoreStateMachine::pushState Apr 03 14:39:04 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:04 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioPushState Apr 03 14:39:04 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:04 main-office-tester volumio[1107]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Apr 03 14:39:04 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:04 main-office-tester volumio[1107]: info: CoreStateMachine::startPlaybackTimer Apr 03 14:39:04 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:04 main-office-tester volumio[1107]: info: [1775252344327] ControllerSpotify::clearAddPlayTrack Apr 03 14:39:04 main-office-tester volumio[1107]: info: Sending Spotify command with payload to local API: /player/play Apr 03 14:39:04 main-office-tester volumio[1107]: info: ------------------------------ 30ms Apr 03 14:39:04 main-office-tester volumio[1107]: info: ------------------------------ 26ms Apr 03 14:39:04 main-office-tester volumio[1107]: info: ------------------------------ 24ms Apr 03 14:39:04 main-office-tester volumio[1107]: info: CoreStateMachine::pushState Apr 03 14:39:04 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:04 main-office-tester volumio[1107]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 14:39:04 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioPushState Apr 03 14:39:04 main-office-tester volumio[1107]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Apr 03 14:39:04 main-office-tester volumio[1107]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Apr 03 14:39:04 main-office-tester volumio[1107]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Apr 03 14:39:04 main-office-tester volumio[1107]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Apr 03 14:39:04 main-office-tester volumio[1107]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Apr 03 14:39:04 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:04 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:04 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:04-07:00" level=debug msg="resolved context of track" uri="spotify:track:3PW8R9LHr6tvhdARHAqG9s" Apr 03 14:39:04 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:04-07:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:3PW8R9LHr6tvhdARHAqG9s" Apr 03 14:39:04 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:04-07:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:3PW8R9LHr6tvhdARHAqG9s" Apr 03 14:39:04 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:04-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 03 14:39:04 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:04-07:00" level=trace msg="emitting websocket event: will_play" Apr 03 14:39:04 main-office-tester volumio[1107]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:3PW8R9LHr6tvhdARHAqG9s","uri":"spotify:track:3PW8R9LHr6tvhdARHAqG9s","play_origin":"go-librespot"}} Apr 03 14:39:04 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:04-07:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 03 14:39:04 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:04-07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1713" Apr 03 14:39:04 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:04-07:00" level=debug msg="selected format OGG_VORBIS_320 (635d38be0e57bbe723c363c39eeb2239360d7619)" uri="spotify:track:3PW8R9LHr6tvhdARHAqG9s" Apr 03 14:39:04 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:04-07:00" level=debug msg="requested aes key for file 635d38be0e57bbe723c363c39eeb2239360d7619, gid: 0yNF0v2ozoM1qoCCMzZjlv" Apr 03 14:39:04 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:04 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:04 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:04 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:04 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:04 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:04-07:00" level=trace msg="found 2 cdn urls" uri="spotify:track:3PW8R9LHr6tvhdARHAqG9s" Apr 03 14:39:05 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:05-07:00" level=debug msg="fetched first chunk of 15, total size is 7389956 bytes" uri="spotify:track:3PW8R9LHr6tvhdARHAqG9s" Apr 03 14:39:05 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:05-07:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames, PCM format = FLOAT_LE" Apr 03 14:39:05 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:05-07:00" level=info msg="loaded track \"White Flag\" (paused: false, position: 0ms, duration: 183120ms, prefetched: false)" uri="spotify:track:3PW8R9LHr6tvhdARHAqG9s" Apr 03 14:39:05 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:05-07:00" level=debug msg="fetched chunk 2/14, size: 524288" uri="spotify:track:3PW8R9LHr6tvhdARHAqG9s" Apr 03 14:39:05 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:05-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 03 14:39:05 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:05-07:00" level=trace msg="scheduling prefetch in 153s" Apr 03 14:39:05 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:05-07:00" level=trace msg="emitting websocket event: metadata" Apr 03 14:39:05 main-office-tester volumio[1107]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0yNF0v2ozoM1qoCCMzZjlv","name":"White Flag","artist_names":["Delta Heavy"],"album_name":"Paradise Lost","album_cover_url":"https://i.scdn.co/image/ab67616d00001e026802b6317d3c124ddd0746f7","position":0,"duration":183120,"release_date":"year:2016 month:3 day:18","track_number":4,"disc_number":1}} Apr 03 14:39:05 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:05-07:00" level=debug msg="fetched chunk 1/14, size: 524288" uri="spotify:track:3PW8R9LHr6tvhdARHAqG9s" Apr 03 14:39:05 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:05-07:00" level=debug msg="fetched chunk 3/14, size: 524288" uri="spotify:track:3PW8R9LHr6tvhdARHAqG9s" Apr 03 14:39:05 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:05-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 03 14:39:05 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:05-07:00" level=trace msg="emitting websocket event: playing" Apr 03 14:39:05 main-office-tester volumio[1107]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:3PW8R9LHr6tvhdARHAqG9s","uri":"spotify:track:3PW8R9LHr6tvhdARHAqG9s","resume":false,"play_origin":"go-librespot"}} Apr 03 14:39:05 main-office-tester volumio[1107]: SPOTIFY: PUSH STATE SPOTIFY Apr 03 14:39:05 main-office-tester volumio[1107]: SPOTIFY: {"status":"play","service":"spop","title":"White Flag","artist":"Delta Heavy","album":"Paradise Lost","albumart":"https://i.scdn.co/image/ab67616d00001e026802b6317d3c124ddd0746f7","uri":"spotify:track:0yNF0v2ozoM1qoCCMzZjlv","trackType":"spotify","seek":0,"duration":183,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 03 14:39:05 main-office-tester volumio[1107]: info: CoreCommandRouter::servicePushState Apr 03 14:39:05 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:05 main-office-tester volumio[1107]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"White Flag","artist":"Delta Heavy","album":"Paradise Lost","albumart":"https://i.scdn.co/image/ab67616d00001e026802b6317d3c124ddd0746f7","uri":"spotify:track:0yNF0v2ozoM1qoCCMzZjlv","trackType":"spotify","seek":0,"duration":183,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 03 14:39:05 main-office-tester volumio[1107]: verbose: CURRENT POSITION 152 Apr 03 14:39:05 main-office-tester volumio[1107]: info: CoreStateMachine::syncState stateService play Apr 03 14:39:05 main-office-tester volumio[1107]: info: CoreStateMachine::syncState currentStatus stop Apr 03 14:39:05 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:05 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:05 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:05 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:05 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:05 main-office-tester volumio[1107]: SPOTIFY: PUSH STATE SPOTIFY Apr 03 14:39:05 main-office-tester volumio[1107]: SPOTIFY: {"status":"play","service":"spop","title":"White Flag","artist":"Delta Heavy","album":"Paradise Lost","albumart":"https://i.scdn.co/image/ab67616d00001e026802b6317d3c124ddd0746f7","uri":"spotify:track:0yNF0v2ozoM1qoCCMzZjlv","trackType":"spotify","seek":0,"duration":183,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 03 14:39:05 main-office-tester volumio[1107]: info: CoreCommandRouter::servicePushState Apr 03 14:39:05 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:05 main-office-tester volumio[1107]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"White Flag","artist":"Delta Heavy","album":"Paradise Lost","albumart":"https://i.scdn.co/image/ab67616d00001e026802b6317d3c124ddd0746f7","uri":"spotify:track:0yNF0v2ozoM1qoCCMzZjlv","trackType":"spotify","seek":0,"duration":183,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 03 14:39:05 main-office-tester volumio[1107]: verbose: CURRENT POSITION 152 Apr 03 14:39:05 main-office-tester volumio[1107]: info: CoreStateMachine::syncState stateService play Apr 03 14:39:05 main-office-tester volumio[1107]: info: CoreStateMachine::syncState currentStatus play Apr 03 14:39:05 main-office-tester volumio[1107]: info: Received an update from plugin. extracting info from payload Apr 03 14:39:05 main-office-tester volumio[1107]: info: CoreStateMachine::pushState Apr 03 14:39:05 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:05 main-office-tester volumio[1107]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 14:39:05 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioPushState Apr 03 14:39:05 main-office-tester volumio[1107]: info: CoreStateMachine::pushState Apr 03 14:39:05 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:05 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioPushState Apr 03 14:39:05 main-office-tester volumio[1107]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Apr 03 14:39:05 main-office-tester volumio[1107]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Apr 03 14:39:06 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:06 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:06 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:06 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:06 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:07 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:07 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:07 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:07 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:07 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:08 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:08 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:08 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:08 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:08 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:09 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:09 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:09 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:09 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:09 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:10 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:10 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:10 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:10 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:10 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:10 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioClearQueue Apr 03 14:39:10 main-office-tester volumio[1107]: info: CoreStateMachine::ClearQueue Apr 03 14:39:10 main-office-tester volumio[1107]: info: CoreStateMachine::stop Apr 03 14:39:10 main-office-tester volumio[1107]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 14:39:10 main-office-tester volumio[1107]: info: CoreStateMachine::stPlaybackTimer Apr 03 14:39:10 main-office-tester volumio[1107]: info: CoreStateMachine::updateTrackBlock Apr 03 14:39:10 main-office-tester volumio[1107]: info: CorePlayQueue::getTrackBlock Apr 03 14:39:10 main-office-tester volumio[1107]: info: CoreStateMachine::pushState Apr 03 14:39:10 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:10 main-office-tester volumio[1107]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 14:39:10 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioPushState Apr 03 14:39:10 main-office-tester volumio[1107]: info: CoreStateMachine::serviceStop Apr 03 14:39:10 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:10 main-office-tester volumio[1107]: info: CoreCommandRouter::serviceStop Apr 03 14:39:10 main-office-tester volumio[1107]: info: Spotify Stop Apr 03 14:39:10 main-office-tester volumio[1107]: SPOTIFY: SPOTIFY STOP Apr 03 14:39:10 main-office-tester volumio[1107]: SPOTIFY: {"status":"play","position":152,"title":"White Flag","artist":"Delta Heavy","album":"Paradise Lost","albumart":"https://i.scdn.co/image/ab67616d0000b2736802b6317d3c124ddd0746f7","uri":"spotify:track:3PW8R9LHr6tvhdARHAqG9s","trackType":"spotify","codec":"ogg","seek":0,"duration":183,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":true,"repeat":true,"repeatSingle":false,"consume":false,"volume":30,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Apr 03 14:39:10 main-office-tester volumio[1107]: info: Sending Spotify command to local API: /player/pause Apr 03 14:39:10 main-office-tester volumio[1107]: info: CorePlayQueue::clearPlayQueue Apr 03 14:39:10 main-office-tester volumio[1107]: info: CorePlayQueue::saveQueue Apr 03 14:39:10 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioPushState Apr 03 14:39:10 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioPushQueue Apr 03 14:39:10 main-office-tester volumio[1107]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Apr 03 14:39:10 main-office-tester volumio[1107]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Apr 03 14:39:10 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:10-07:00" level=debug msg="pause track at 5650ms" Apr 03 14:39:11 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:11-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 03 14:39:11 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:11-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 03 14:39:11 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:11-07:00" level=trace msg="emitting websocket event: paused" Apr 03 14:39:11 main-office-tester volumio[1107]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:3PW8R9LHr6tvhdARHAqG9s","uri":"spotify:track:3PW8R9LHr6tvhdARHAqG9s","play_origin":"go-librespot"}} Apr 03 14:39:11 main-office-tester volumio[1107]: SPOTIFY: PUSH STATE SPOTIFY Apr 03 14:39:11 main-office-tester volumio[1107]: SPOTIFY: {"status":"pause","service":"spop","title":"White Flag","artist":"Delta Heavy","album":"Paradise Lost","albumart":"https://i.scdn.co/image/ab67616d00001e026802b6317d3c124ddd0746f7","uri":"spotify:track:0yNF0v2ozoM1qoCCMzZjlv","trackType":"spotify","seek":5000,"duration":183,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 03 14:39:11 main-office-tester volumio[1107]: info: CoreCommandRouter::servicePushState Apr 03 14:39:11 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:11 main-office-tester volumio[1107]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"White Flag","artist":"Delta Heavy","album":"Paradise Lost","albumart":"https://i.scdn.co/image/ab67616d00001e026802b6317d3c124ddd0746f7","uri":"spotify:track:0yNF0v2ozoM1qoCCMzZjlv","trackType":"spotify","seek":5000,"duration":183,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 03 14:39:11 main-office-tester volumio[1107]: verbose: CURRENT POSITION 152 Apr 03 14:39:11 main-office-tester volumio[1107]: info: CoreStateMachine::syncState stateService pause Apr 03 14:39:11 main-office-tester volumio[1107]: info: CoreStateMachine::syncState currentStatus stop Apr 03 14:39:11 main-office-tester volumio[1107]: info: CoreStateMachine::pushState Apr 03 14:39:11 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:11 main-office-tester volumio[1107]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 14:39:11 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioPushState Apr 03 14:39:11 main-office-tester volumio[1107]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Apr 03 14:39:11 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:11 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:11 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:11 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:11 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:12 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:12 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:12 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:12 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:12 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:13 main-office-tester volumio[1107]: info: CoreCommandRouter::executeOnPlugin: pandora , handleBrowseUri Apr 03 14:39:13 main-office-tester volumio[1107]: info: [1775252353410] ControllerPandora::handleBrowseUri Apr 03 14:39:13 main-office-tester volumio[1107]: info: [1775252353410] ControllerPandora::checkForExpiredStations Apr 03 14:39:13 main-office-tester volumio[1107]: info: [1775252353410] [Pandora] checkForExpiredStations: Stations expired Apr 03 14:39:13 main-office-tester volumio[1107]: info: [1775252353411] ControllerPandora::PandoraHandler::fillStationData Apr 03 14:39:13 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:13 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:13 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:13 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:13 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:14 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:14 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:14 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:14 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:14 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:15 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:15 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:15 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:15 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:15 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:16 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:16 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:16 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:16 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:16 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:17 main-office-tester systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 5662. Apr 03 14:39:17 main-office-tester systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Apr 03 14:39:17 main-office-tester systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Apr 03 14:39:17 main-office-tester upmpdcli[7774]: Could not open config: /tmp/upmpdcli.conf Apr 03 14:39:17 main-office-tester systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Apr 03 14:39:17 main-office-tester systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Apr 03 14:39:17 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:17 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:17 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:17 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:17 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:18 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:18 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:18 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:18 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:18 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:19 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:19 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:19 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:19 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:19 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:20 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:20 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:20 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:20 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:20 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:21 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:21-07:00" level=trace msg="sent dealer ping" Apr 03 14:39:21 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:21-07:00" level=trace msg="received dealer pong" Apr 03 14:39:21 main-office-tester volumio[1107]: info: CoreCommandRouter::executeOnPlugin: pandora , handleBrowseUri Apr 03 14:39:21 main-office-tester volumio[1107]: info: [1775252361591] ControllerPandora::handleBrowseUri Apr 03 14:39:21 main-office-tester volumio[1107]: info: [1775252361591] ControllerPandora::checkForExpiredStations Apr 03 14:39:21 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:21 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:21 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:21 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:21 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:22 main-office-tester systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Apr 03 14:39:22 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:22 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:22 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:22 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:22 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:23 main-office-tester systemd[1]: setdatetime-helper.service: Deactivated successfully. Apr 03 14:39:23 main-office-tester systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Apr 03 14:39:23 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:23 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:23 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:23 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:23 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:24 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:24 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:24 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:24 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:24 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:25 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:25 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:25 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:25 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:25 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:26 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:26 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:26 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:26 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:26 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:27 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:27 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:27 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:27 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:27 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:28 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:28 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:28 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:28 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:28 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:30 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:30 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:30 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:30 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:30 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:31 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:31 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:31 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:31 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:31 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:31 main-office-tester volumio[1107]: info: CoreCommandRouter::executeOnPlugin: pandora , handleBrowseUri Apr 03 14:39:31 main-office-tester volumio[1107]: info: [1775252371081] ControllerPandora::handleBrowseUri Apr 03 14:39:31 main-office-tester volumio[1107]: info: [1775252371082] ControllerPandora::checkForExpiredStations Apr 03 14:39:32 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:32 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:32 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:32 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:32 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:32 main-office-tester systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 5663. Apr 03 14:39:32 main-office-tester systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Apr 03 14:39:33 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:33 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:33 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:33 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:33 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:33 main-office-tester systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Apr 03 14:39:33 main-office-tester upmpdcli[7830]: Could not open config: /tmp/upmpdcli.conf Apr 03 14:39:33 main-office-tester systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Apr 03 14:39:33 main-office-tester systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Apr 03 14:39:34 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:34 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:34 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:34 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:34 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:35 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:35 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:35 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:35 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:35 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:36 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:36 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:36 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:36 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:36 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:37 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:37 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:37 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:37 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:37 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:38 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:38 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:38 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:38 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:38 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:39 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:39 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:39 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:39 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:39 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:40 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:40 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:40 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:40 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:40 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:41 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:41 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:41 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:41 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:41 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:42 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:42 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:42 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:42 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:42 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:43 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:43 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:43 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:43 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:43 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:44 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:44 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:44 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:44 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:44 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:45 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:45 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:45 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:45 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:45 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:46 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:46 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:46 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:46 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:46 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:47 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:47 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:47 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:47 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:47 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:48 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:48 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:48 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:48 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:48 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:48 main-office-tester systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 5664. Apr 03 14:39:48 main-office-tester systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Apr 03 14:39:48 main-office-tester systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Apr 03 14:39:48 main-office-tester upmpdcli[7846]: Could not open config: /tmp/upmpdcli.conf Apr 03 14:39:48 main-office-tester systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Apr 03 14:39:48 main-office-tester systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Apr 03 14:39:49 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:49 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:49 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:49 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:49 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:50 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:50 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:50 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:50 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:50 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:51 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:51 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:51 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:51 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:51 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:51 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:51-07:00" level=trace msg="sent dealer ping" Apr 03 14:39:51 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:51-07:00" level=trace msg="received dealer pong" Apr 03 14:39:52 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:52 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:52 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:52 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:52 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:53 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:53 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:53 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:53 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:53 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:54 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:54 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:54 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:54 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:54 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:54 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:54-07:00" level=trace msg="received accesspoint ping" Apr 03 14:39:54 main-office-tester go-librespot[1411]: time="2026-04-03T14:39:54-07:00" level=trace msg="received accesspoint pong ack" Apr 03 14:39:55 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:55 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:55 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:55 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:55 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:56 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:56 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:56 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:56 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:56 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:57 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:57 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:57 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:57 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:57 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:58 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:58 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:58 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:58 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:58 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:39:59 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:39:59 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:39:59 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:39:59 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:39:59 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:00 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:00 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:00 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:00 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:00 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:01 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:01 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:01 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:01 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:01 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:01 main-office-tester volumio[1107]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 03 14:40:01 main-office-tester volumio[1107]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 03 14:40:02 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:02 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:02 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:02 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:02 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:03 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:03 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:03 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:03 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:03 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:03 main-office-tester systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 5665. Apr 03 14:40:03 main-office-tester systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Apr 03 14:40:03 main-office-tester systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Apr 03 14:40:03 main-office-tester upmpdcli[7877]: Could not open config: /tmp/upmpdcli.conf Apr 03 14:40:03 main-office-tester systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Apr 03 14:40:03 main-office-tester systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Apr 03 14:40:04 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:04 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:04 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:04 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:04 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:04 main-office-tester volumio[1107]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 03 14:40:05 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:05 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:05 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:05 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:05 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:06 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:06 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:06 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:06 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:06 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:07 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:07 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:07 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:07 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:07 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:08 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:08 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:08 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:08 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:08 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:09 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:09 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:09 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:09 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:09 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:10 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:10 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:10 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:10 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:10 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:11 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:11 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:11 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:11 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:11 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:12 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:12 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:12 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:12 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:12 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:13 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:13 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:13 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:13 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:13 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:14 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:14 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:14 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:14 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:14 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:15 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:15 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:15 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:15 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:15 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:16 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:16 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:16 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:16 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:16 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:17 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:17 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:17 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:17 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:17 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:18 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:18 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:18 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:18 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:18 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:18 main-office-tester systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 5666. Apr 03 14:40:18 main-office-tester systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Apr 03 14:40:18 main-office-tester systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Apr 03 14:40:18 main-office-tester upmpdcli[7908]: Could not open config: /tmp/upmpdcli.conf Apr 03 14:40:18 main-office-tester systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Apr 03 14:40:18 main-office-tester systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Apr 03 14:40:19 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:19 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:19 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:19 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:19 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:20 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:20 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:20 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:20 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:20 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:21 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:21 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:21 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:21 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:21 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:21 main-office-tester go-librespot[1411]: time="2026-04-03T14:40:21-07:00" level=trace msg="sent dealer ping" Apr 03 14:40:21 main-office-tester go-librespot[1411]: time="2026-04-03T14:40:21-07:00" level=trace msg="received dealer pong" Apr 03 14:40:22 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:22 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:22 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:22 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:22 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:23 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:23 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:23 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:23 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:23 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:24 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:24 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:24 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:24 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:24 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:25 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:25 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:25 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:25 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:25 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:26 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:26 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:26 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:26 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:26 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:27 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:27 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:27 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:27 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:27 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:28 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:28 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:28 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:28 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:28 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:29 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:29 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:29 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:29 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:29 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:30 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:30 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:30 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:30 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:30 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:30 main-office-tester volumio[1107]: info: CoreCommandRouter::executeOnPlugin: pandora , handleBrowseUri Apr 03 14:40:30 main-office-tester volumio[1107]: info: [1775252430915] ControllerPandora::handleBrowseUri Apr 03 14:40:30 main-office-tester volumio[1107]: info: [1775252430915] ControllerPandora::checkForExpiredStations Apr 03 14:40:31 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:31 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:31 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:31 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:31 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:32 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetState Apr 03 14:40:32 main-office-tester volumio[1107]: info: CorePlayQueue::getTrack 152 Apr 03 14:40:32 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetQueue Apr 03 14:40:32 main-office-tester volumio[1107]: info: CoreStateMachine::getQueue Apr 03 14:40:32 main-office-tester volumio[1107]: info: CorePlayQueue::getQueue Apr 03 14:40:32 main-office-tester volumio[1107]: info: CoreCommandRouter::volumioGetVisibleSources Apr 03 14:40:32 main-office-tester volumio[1107]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 03 14:40:32 main-office-tester volumio[1107]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 03 14:40:32 main-office-tester volumio[1107]: Error Apr 03 14:40:32 main-office-tester volumio[1107]: at /volumio/app/plugins/music_service/webradio/index.js:427:31 Apr 03 14:40:32 main-office-tester volumio[1107]: at Request.handleRequestResponse [as _callback] (/volumio/node_modules/unirest/index.js:444:15) Apr 03 14:40:32 main-office-tester volumio[1107]: at self.callback (/volumio/node_modules/request/request.js:185:22) Apr 03 14:40:32 main-office-tester volumio[1107]: at Request.emit (node:events:514:28) Apr 03 14:40:32 main-office-tester volumio[1107]: at Request.onRequestError (/volumio/node_modules/request/request.js:877:8) Apr 03 14:40:32 main-office-tester volumio[1107]: at ClientRequest.emit (node:events:514:28) Apr 03 14:40:32 main-office-tester volumio[1107]: at Socket.socketErrorListener (node:_http_client:495:9) Apr 03 14:40:32 main-office-tester volumio[1107]: at Socket.emit (node:events:514:28) Apr 03 14:40:32 main-office-tester volumio[1107]: at emitErrorNT (node:internal/streams/destroy:151:8) Apr 03 14:40:32 main-office-tester volumio[1107]: at emitErrorCloseNT (node:internal/streams/destroy:116:3) Apr 03 14:40:32 main-office-tester volumio[1107]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 03 14:40:33 main-office-tester sudo[7939]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-03 14:39' Apr 03 14:40:33 main-office-tester sudo[7939]: 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="dc61260dec5515dafd2b634881860b4c46c919ff" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Mar 6 16:46:58 UTC 2026" VOLUMIO_VERSION="4.103" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="aa741395b8bfc648ff5d04e312f53d2c"