-- Logs begin at Fri 2025-09-05 07:06:26 EEST, end at Sat 2025-09-06 06:06:23 EEST. -- Sep 06 06:05:02 volumio volumio[926]: info: CALLMETHOD: music_service mpd savePlaybackOptions [object Object] Sep 06 06:05:02 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: mpd , savePlaybackOptions Sep 06 06:05:02 volumio sudo[2067]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 06 06:05:02 volumio sudo[2067]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 06 06:05:02 volumio sudo[2067]: pam_unix(sudo:session): session closed for user root Sep 06 06:05:02 volumio volumio[926]: info: MPD Permissions set Sep 06 06:05:02 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 06:05:02 volumio sudo[2070]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 06 06:05:02 volumio sudo[2070]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 06 06:05:02 volumio systemd[1]: Stopping Music Player Daemon... Sep 06 06:05:02 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 06 06:05:02 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 06:05:03 volumio systemd[1]: mpd.service: Succeeded. Sep 06 06:05:03 volumio systemd[1]: Stopped Music Player Daemon. Sep 06 06:05:03 volumio systemd[1]: Starting Music Player Daemon... Sep 06 06:05:03 volumio sudo[2076]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 06 06:05:03 volumio sudo[2076]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 06 06:05:03 volumio sudo[2076]: pam_unix(sudo:session): session closed for user root Sep 06 06:05:03 volumio volumio[926]: error: Upnp client error: Error: This socket has been ended by the other party Sep 06 06:05:04 volumio volumio[926]: info: CALLMETHOD: music_service mpd savePlaybackOptions [object Object] Sep 06 06:05:04 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: mpd , savePlaybackOptions Sep 06 06:05:04 volumio sudo[2083]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 06 06:05:04 volumio sudo[2083]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 06 06:05:04 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 06:05:04 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 06:05:04 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 06:05:04 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 06:05:04 volumio sudo[2083]: pam_unix(sudo:session): session closed for user root Sep 06 06:05:04 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 06:05:04 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 06:05:04 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 06:05:04 volumio sudo[2086]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 06 06:05:04 volumio sudo[2086]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 06 06:05:04 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 06 06:05:04 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 06:05:04 volumio volumio[926]: info: MPD Permissions set Sep 06 06:05:04 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Sep 06 06:05:04 volumio systemd[1]: mpd.service: Succeeded. Sep 06 06:05:04 volumio systemd[1]: Stopped Music Player Daemon. Sep 06 06:05:05 volumio systemd[1]: Starting Music Player Daemon... Sep 06 06:05:05 volumio sudo[2092]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 06 06:05:05 volumio sudo[2092]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 06 06:05:05 volumio sudo[2092]: pam_unix(sudo:session): session closed for user root Sep 06 06:05:05 volumio volumio[926]: info: CALLMETHOD: music_service mpd savePlaybackOptions [object Object] Sep 06 06:05:05 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: mpd , savePlaybackOptions Sep 06 06:05:05 volumio sudo[2097]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 06 06:05:05 volumio sudo[2097]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 06 06:05:05 volumio sudo[2097]: pam_unix(sudo:session): session closed for user root Sep 06 06:05:05 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 06:05:05 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 06:05:05 volumio sudo[2100]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 06 06:05:05 volumio sudo[2100]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 06 06:05:05 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Sep 06 06:05:05 volumio systemd[1]: mpd.service: Succeeded. Sep 06 06:05:05 volumio systemd[1]: Stopped Music Player Daemon. Sep 06 06:05:05 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 06 06:05:05 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 06:05:05 volumio volumio[926]: info: MPD Permissions set Sep 06 06:05:05 volumio systemd[1]: Starting Music Player Daemon... Sep 06 06:05:05 volumio sudo[2106]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 06 06:05:05 volumio sudo[2106]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 06 06:05:05 volumio sudo[2106]: pam_unix(sudo:session): session closed for user root Sep 06 06:05:06 volumio volumio[926]: info: CoreCommandRouter::volumioGetState Sep 06 06:05:06 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:07 volumio mpd[2108]: Sep 06 06:05 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 06 06:05:07 volumio systemd[1]: Started Music Player Daemon. Sep 06 06:05:07 volumio sudo[2070]: pam_unix(sudo:session): session closed for user root Sep 06 06:05:07 volumio sudo[2100]: pam_unix(sudo:session): session closed for user root Sep 06 06:05:07 volumio sudo[2086]: pam_unix(sudo:session): session closed for user root Sep 06 06:05:07 volumio volumio[926]: error: MPD error: The expression evaluated to a falsy value: Sep 06 06:05:07 volumio volumio[926]: assert.ok(self.idling) Sep 06 06:05:07 volumio volumio[926]: error: The expression evaluated to a falsy value: Sep 06 06:05:07 volumio volumio[926]: assert.ok(self.idling) Sep 06 06:05:07 volumio volumio[926]: error: MPD error: The expression evaluated to a falsy value: Sep 06 06:05:07 volumio volumio[926]: assert.ok(self.idling) Sep 06 06:05:07 volumio volumio[926]: error: The expression evaluated to a falsy value: Sep 06 06:05:07 volumio volumio[926]: assert.ok(self.idling) Sep 06 06:05:07 volumio volumio[926]: error: updateQueue error: null Sep 06 06:05:12 volumio go-librespot[15003]: time="2025-09-06T06:05:12+03:00" level=trace msg="sent dealer ping" Sep 06 06:05:13 volumio go-librespot[15003]: time="2025-09-06T06:05:13+03:00" level=trace msg="received dealer pong" Sep 06 06:05:16 volumio volumio[926]: info: CoreCommandRouter::volumioNext Sep 06 06:05:16 volumio volumio[926]: info: CoreStateMachine::next Sep 06 06:05:16 volumio volumio[926]: info: CoreStateMachine::stop Sep 06 06:05:16 volumio volumio[926]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 06 06:05:16 volumio volumio[926]: info: CoreStateMachine::stPlaybackTimer Sep 06 06:05:16 volumio volumio[926]: info: CoreStateMachine::updateTrackBlock Sep 06 06:05:16 volumio volumio[926]: info: CorePlayQueue::getTrackBlock Sep 06 06:05:16 volumio volumio[926]: info: CoreStateMachine::pushState Sep 06 06:05:16 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:16 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 06 06:05:16 volumio volumio[926]: info: CoreCommandRouter::volumioPushState Sep 06 06:05:16 volumio volumio[926]: info: CoreStateMachine::serviceStop Sep 06 06:05:16 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:16 volumio volumio[926]: info: CoreCommandRouter::serviceStop Sep 06 06:05:16 volumio volumio[926]: info: ControllerMpd::stop Sep 06 06:05:16 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand stop Sep 06 06:05:16 volumio volumio[926]: info: [ASDebug] CurState: stop PrevState: play Sep 06 06:05:16 volumio volumio[926]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Sep 06 06:05:16 volumio volumio[926]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Sep 06 06:05:16 volumio volumio[926]: info: sendMpdCommand stop took 13 milliseconds Sep 06 06:05:16 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:16 volumio volumio[926]: info: CoreStateMachine::pushState Sep 06 06:05:16 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:16 volumio volumio[926]: info: CoreCommandRouter::volumioPushState Sep 06 06:05:16 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:16 volumio volumio[926]: verbose: STATE SERVICE {"status":"stop","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is3-ssl.mzstatic.com/image/thumb/Music125/v4/4f/fe/e6/4ffee641-1876-29c6-2307-0dcdc660cd9a/source/600x600bb.jpg","name":"Red Hot Chili Peppers - Scar Tissue","title":"Scar Tissue","artist":"90s90s Hits","album":"","streaming":true,"disableUiControls":true,"duration":"206","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Sep 06 06:05:16 volumio volumio[926]: verbose: CURRENT POSITION 0 Sep 06 06:05:16 volumio volumio[926]: info: CoreStateMachine::syncState stateService stop Sep 06 06:05:16 volumio volumio[926]: info: CoreStateMachine::syncState currentStatus stop Sep 06 06:05:16 volumio volumio[926]: info: CoreStateMachine::pushState Sep 06 06:05:16 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:16 volumio volumio[926]: info: CoreCommandRouter::volumioPushState Sep 06 06:05:16 volumio volumio[926]: info: No code Sep 06 06:05:16 volumio volumio[926]: info: CoreStateMachine::pushState Sep 06 06:05:16 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:16 volumio volumio[926]: info: CoreCommandRouter::volumioPushState Sep 06 06:05:16 volumio volumio[926]: info: CoreStateMachine::play index undefined Sep 06 06:05:16 volumio volumio[926]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 06 06:05:16 volumio volumio[926]: info: CorePlayQueue::getTrack 1 Sep 06 06:05:16 volumio volumio[926]: info: [ASDebug] CurState: stop PrevState: play Sep 06 06:05:16 volumio volumio[926]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Sep 06 06:05:16 volumio volumio[926]: info: [ASDebug] CurState: stop PrevState: play Sep 06 06:05:16 volumio volumio[926]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Sep 06 06:05:16 volumio volumio[926]: info: [ASDebug] CurState: stop PrevState: play Sep 06 06:05:16 volumio volumio[926]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Sep 06 06:05:16 volumio volumio[926]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Sep 06 06:05:16 volumio volumio[926]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Sep 06 06:05:16 volumio volumio[926]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Sep 06 06:05:16 volumio volumio[926]: info: CoreCommandRouter::volumioGetState Sep 06 06:05:16 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:16 volumio volumio[926]: info: Listing playlists Sep 06 06:05:16 volumio volumio[926]: info: Listing playlists Sep 06 06:05:16 volumio volumio[926]: info: [ASDebug] Togle GPIO: OFF Sep 06 06:05:19 volumio volumio[926]: info: CoreCommandRouter::volumioPlay Sep 06 06:05:19 volumio volumio[926]: info: CoreStateMachine::play index undefined Sep 06 06:05:19 volumio volumio[926]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 06 06:05:19 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:19 volumio volumio[926]: info: CoreStateMachine::startPlaybackTimer Sep 06 06:05:19 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:19 volumio volumio[926]: info: [1757127919309] [80s80s] clearAddPlayTrack url: http://streams.90s90s.de/pop/mp3-192/volumio Sep 06 06:05:19 volumio volumio[926]: info: [1757127919310] [80s80s] getContentOfUrl started with url http://iris-90s90s.loverad.io/flow.json?station=141&count=2 Sep 06 06:05:19 volumio volumio[926]: info: [1757127919549] [80s80s] received new event containing 2 songs. Sep 06 06:05:19 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand stop Sep 06 06:05:19 volumio volumio[926]: info: sendMpdCommand stop took 1 milliseconds Sep 06 06:05:19 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand clear Sep 06 06:05:19 volumio volumio[926]: info: Sep 06 06:05:19 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:19 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:19 volumio volumio[926]: info: sendMpdCommand clear took 3 milliseconds Sep 06 06:05:19 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand consume 1 Sep 06 06:05:19 volumio volumio[926]: info: Sep 06 06:05:19 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:19 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:19 volumio volumio[926]: info: Sep 06 06:05:19 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:19 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:19 volumio volumio[926]: error: updateQueue error: null Sep 06 06:05:19 volumio volumio[926]: info: Sep 06 06:05:19 volumio volumio[926]: ---------------------------- MPD announces state update: options Sep 06 06:05:19 volumio volumio[926]: error: updateQueue error: null Sep 06 06:05:19 volumio volumio[926]: info: ------------------------------ 7ms Sep 06 06:05:19 volumio volumio[926]: info: sendMpdCommand consume 1 took 6 milliseconds Sep 06 06:05:19 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:19 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:19 volumio volumio[926]: info: ------------------------------ 5ms Sep 06 06:05:19 volumio volumio[926]: info: [1757127919562] [80s80s] adding url: http://streams.90s90s.de/pop/mp3-192/volumio Sep 06 06:05:19 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand add "http://streams.90s90s.de/pop/mp3-192/volumio" Sep 06 06:05:19 volumio volumio[926]: info: Sep 06 06:05:19 volumio volumio[926]: ---------------------------- MPD announces state update: options Sep 06 06:05:19 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:19 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:19 volumio volumio[926]: info: Sep 06 06:05:19 volumio volumio[926]: ---------------------------- MPD announces state update: options Sep 06 06:05:19 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:19 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:19 volumio volumio[926]: error: updateQueue error: null Sep 06 06:05:19 volumio volumio[926]: info: Sep 06 06:05:19 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:19 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:19 volumio volumio[926]: info: ------------------------------ 9ms Sep 06 06:05:19 volumio volumio[926]: info: sendMpdCommand status took 7 milliseconds Sep 06 06:05:19 volumio volumio[926]: info: sendMpdCommand add "http://streams.90s90s.de/pop/mp3-192/volumio" took 6 milliseconds Sep 06 06:05:19 volumio volumio[926]: info: sendMpdCommand status took 4 milliseconds Sep 06 06:05:19 volumio volumio[926]: info: sendMpdCommand status took 4 milliseconds Sep 06 06:05:19 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:19 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand play Sep 06 06:05:19 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:19 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:19 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:19 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:19 volumio volumio[926]: info: CoreStateMachine::pushState Sep 06 06:05:19 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:19 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 06 06:05:19 volumio volumio[926]: info: CoreCommandRouter::volumioPushState Sep 06 06:05:19 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:19 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:19 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:19 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:19 volumio volumio[926]: info: CoreStateMachine::pushState Sep 06 06:05:19 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:19 volumio volumio[926]: info: CoreCommandRouter::volumioPushState Sep 06 06:05:19 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:19 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:19 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:19 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:19 volumio volumio[926]: info: CoreStateMachine::pushState Sep 06 06:05:19 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:19 volumio volumio[926]: info: CoreCommandRouter::volumioPushState Sep 06 06:05:19 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:19 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:19 volumio volumio[926]: info: ------------------------------ 30ms Sep 06 06:05:19 volumio volumio[926]: info: ------------------------------ 33ms Sep 06 06:05:19 volumio volumio[926]: info: ------------------------------ 32ms Sep 06 06:05:19 volumio volumio[926]: info: Sep 06 06:05:19 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:19 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:19 volumio volumio[926]: info: Sep 06 06:05:19 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:19 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:19 volumio volumio[926]: info: ------------------------------ 35ms Sep 06 06:05:19 volumio volumio[926]: info: sendMpdCommand play took 29 milliseconds Sep 06 06:05:19 volumio volumio[926]: info: ------------------------------ 4ms Sep 06 06:05:19 volumio volumio[926]: info: ------------------------------ 3ms Sep 06 06:05:19 volumio volumio[926]: info: [1757127919602] [80s80s] Pushing the next song state: Red Hot Chili Peppers - Scar Tissue Sep 06 06:05:19 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:19 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:19 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:19 volumio volumio[926]: verbose: STATE SERVICE {"status":"play","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is3-ssl.mzstatic.com/image/thumb/Music125/v4/4f/fe/e6/4ffee641-1876-29c6-2307-0dcdc660cd9a/source/600x600bb.jpg","name":"Red Hot Chili Peppers - Scar Tissue","title":"Scar Tissue","artist":"90s90s Hits","album":"","streaming":true,"disableUiControls":true,"duration":"206","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Sep 06 06:05:19 volumio volumio[926]: verbose: CURRENT POSITION 0 Sep 06 06:05:19 volumio volumio[926]: info: CoreStateMachine::syncState stateService play Sep 06 06:05:19 volumio volumio[926]: info: CoreStateMachine::syncState currentStatus stop Sep 06 06:05:19 volumio volumio[926]: info: [1757127919604] [80s80s] PlayNextTrack API delay: 30 Sep 06 06:05:19 volumio volumio[926]: info: [1757127919609] [80s80s] Setting timer to: 206000 milliseconds. Sep 06 06:05:19 volumio volumio[926]: info: [ASDebug] CurState: stop PrevState: stop Sep 06 06:05:19 volumio volumio[926]: info: [ASDebug] CurState: stop PrevState: stop Sep 06 06:05:19 volumio volumio[926]: info: [ASDebug] CurState: stop PrevState: stop Sep 06 06:05:19 volumio volumio[926]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Sep 06 06:05:19 volumio volumio[926]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Sep 06 06:05:19 volumio volumio[926]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Sep 06 06:05:22 volumio volumio[926]: info: Sep 06 06:05:22 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:22 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:22 volumio volumio[926]: info: Sep 06 06:05:22 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:22 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:22 volumio volumio[926]: info: Sep 06 06:05:22 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:22 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:22 volumio volumio[926]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Sep 06 06:05:22 volumio volumio[926]: info: FusionDsp - ---- read samplerate from file: 44100 Sep 06 06:05:22 volumio volumio[926]: info: FusionDsp - If filter freq >samplerate/2 then disable it Sep 06 06:05:22 volumio volumio[926]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Sep 06 06:05:22 volumio volumio[926]: info: FusionDsp - ---- read samplerate from file: 44100 Sep 06 06:05:22 volumio volumio[926]: info: FusionDsp - If filter freq >samplerate/2 then disable it Sep 06 06:05:22 volumio volumio[926]: info: Sep 06 06:05:22 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:22 volumio volumio[926]: info: sendMpdCommand status took 35 milliseconds Sep 06 06:05:22 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:22 volumio volumio[926]: info: sendMpdCommand status took 25 milliseconds Sep 06 06:05:22 volumio volumio[926]: info: sendMpdCommand status took 25 milliseconds Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:22 volumio volumio[926]: info: Sep 06 06:05:22 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:22 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:22 volumio volumio[926]: info: Sep 06 06:05:22 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:22 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:22 volumio volumio[926]: info: Sep 06 06:05:22 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:22 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:22 volumio volumio[926]: info: Sep 06 06:05:22 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:22 volumio volumio[926]: info: Sep 06 06:05:22 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:22 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:22 volumio volumio[926]: info: Sep 06 06:05:22 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:22 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:22 volumio volumio[926]: info: sendMpdCommand status took 16 milliseconds Sep 06 06:05:22 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:22 volumio volumio[926]: info: sendMpdCommand playlistinfo took 16 milliseconds Sep 06 06:05:22 volumio volumio[926]: info: sendMpdCommand playlistinfo took 15 milliseconds Sep 06 06:05:22 volumio volumio[926]: info: sendMpdCommand playlistinfo took 14 milliseconds Sep 06 06:05:22 volumio volumio[926]: info: sendMpdCommand status took 13 milliseconds Sep 06 06:05:22 volumio volumio[926]: info: sendMpdCommand status took 13 milliseconds Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:22 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:22 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:22 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:22 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:22 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:22 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:22 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:22 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:22 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:22 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:22 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:22 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:22 volumio volumio[926]: info: ------------------------------ 67ms Sep 06 06:05:22 volumio volumio[926]: info: ------------------------------ 57ms Sep 06 06:05:22 volumio volumio[926]: info: ------------------------------ 55ms Sep 06 06:05:22 volumio volumio[926]: info: Sep 06 06:05:22 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:22 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:22 volumio volumio[926]: info: Sep 06 06:05:22 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:22 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:22 volumio volumio[926]: info: Sep 06 06:05:22 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:22 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:22 volumio volumio[926]: info: Sep 06 06:05:22 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:22 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:22 volumio volumio[926]: error: FusionDsp - WebSocket error: [object Object] Sep 06 06:05:22 volumio volumio[926]: error: FusionDsp - WebSocket error: [object Object] Sep 06 06:05:22 volumio volumio[926]: info: ------------------------------ 31ms Sep 06 06:05:22 volumio volumio[926]: info: sendMpdCommand status took 24 milliseconds Sep 06 06:05:22 volumio volumio[926]: info: ------------------------------ 28ms Sep 06 06:05:22 volumio volumio[926]: info: sendMpdCommand status took 24 milliseconds Sep 06 06:05:22 volumio volumio[926]: info: sendMpdCommand playlistinfo took 20 milliseconds Sep 06 06:05:22 volumio volumio[926]: info: sendMpdCommand playlistinfo took 17 milliseconds Sep 06 06:05:22 volumio volumio[926]: info: sendMpdCommand playlistinfo took 17 milliseconds Sep 06 06:05:22 volumio volumio[926]: info: ------------------------------ 12ms Sep 06 06:05:22 volumio volumio[926]: info: sendMpdCommand status took 12 milliseconds Sep 06 06:05:22 volumio volumio[926]: info: ------------------------------ 11ms Sep 06 06:05:22 volumio volumio[926]: info: sendMpdCommand status took 9 milliseconds Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:22 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:22 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:22 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:22 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:22 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:22 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:22 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:22 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:22 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:22 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:22 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:22 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:22 volumio volumio[926]: info: ------------------------------ 53ms Sep 06 06:05:22 volumio volumio[926]: info: ------------------------------ 47ms Sep 06 06:05:22 volumio volumio[926]: info: ------------------------------ 45ms Sep 06 06:05:22 volumio volumio[926]: info: sendMpdCommand playlistinfo took 8 milliseconds Sep 06 06:05:22 volumio volumio[926]: info: sendMpdCommand playlistinfo took 7 milliseconds Sep 06 06:05:22 volumio volumio[926]: info: sendMpdCommand playlistinfo took 7 milliseconds Sep 06 06:05:22 volumio volumio[926]: info: sendMpdCommand playlistinfo took 6 milliseconds Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:22 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:22 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:22 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:22 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:22 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:22 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:22 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:22 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:22 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:22 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:22 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:22 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:22 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:22 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:22 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:22 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:22 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:22 volumio volumio[926]: info: ------------------------------ 49ms Sep 06 06:05:22 volumio volumio[926]: info: ------------------------------ 45ms Sep 06 06:05:22 volumio volumio[926]: info: ------------------------------ 28ms Sep 06 06:05:22 volumio volumio[926]: info: ------------------------------ 26ms Sep 06 06:05:26 volumio volumio[926]: info: CoreCommandRouter::volumioGetState Sep 06 06:05:26 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:33 volumio volumio[926]: info: Preload queue cleared Sep 06 06:05:33 volumio volumio[926]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 06 06:05:33 volumio volumio[926]: info: CoreStateMachine::ClearQueue Sep 06 06:05:33 volumio volumio[926]: info: CoreStateMachine::stop Sep 06 06:05:33 volumio volumio[926]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 06 06:05:33 volumio volumio[926]: info: CoreStateMachine::stPlaybackTimer Sep 06 06:05:33 volumio volumio[926]: info: CoreStateMachine::updateTrackBlock Sep 06 06:05:33 volumio volumio[926]: info: CorePlayQueue::getTrackBlock Sep 06 06:05:33 volumio volumio[926]: info: CoreStateMachine::pushState Sep 06 06:05:33 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:33 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 06 06:05:33 volumio volumio[926]: info: CoreCommandRouter::volumioPushState Sep 06 06:05:33 volumio volumio[926]: info: CoreStateMachine::serviceStop Sep 06 06:05:33 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:33 volumio volumio[926]: info: CoreCommandRouter::serviceStop Sep 06 06:05:33 volumio volumio[926]: info: ControllerMpd::stop Sep 06 06:05:33 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand stop Sep 06 06:05:33 volumio volumio[926]: info: CorePlayQueue::clearPlayQueue Sep 06 06:05:33 volumio volumio[926]: info: CorePlayQueue::saveQueue Sep 06 06:05:33 volumio volumio[926]: info: CoreCommandRouter::volumioPushQueue Sep 06 06:05:33 volumio volumio[926]: info: CoreStateMachine::addQueueItems Sep 06 06:05:33 volumio volumio[926]: info: CorePlayQueue::addQueueItems Sep 06 06:05:33 volumio volumio[926]: info: Preload queue cleared Sep 06 06:05:33 volumio volumio[926]: info: Adding Item to queue: webnineties/0 Sep 06 06:05:33 volumio volumio[926]: info: Using cached record of: webnineties/0 Sep 06 06:05:33 volumio volumio[926]: info: CoreCommandRouter::volumioPushQueue Sep 06 06:05:33 volumio volumio[926]: info: CorePlayQueue::saveQueue Sep 06 06:05:33 volumio volumio[926]: info: CoreStateMachine::updateTrackBlock Sep 06 06:05:33 volumio volumio[926]: info: CorePlayQueue::getTrackBlock Sep 06 06:05:33 volumio volumio[926]: info: CoreCommandRouter::volumioPlay Sep 06 06:05:33 volumio volumio[926]: info: CoreStateMachine::play index 0 Sep 06 06:05:33 volumio volumio[926]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 06 06:05:33 volumio volumio[926]: info: CoreStateMachine::stop Sep 06 06:05:33 volumio volumio[926]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 06 06:05:33 volumio volumio[926]: info: CoreStateMachine::play index undefined Sep 06 06:05:33 volumio volumio[926]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 06 06:05:33 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:33 volumio volumio[926]: info: CoreStateMachine::startPlaybackTimer Sep 06 06:05:33 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:33 volumio volumio[926]: info: [1757127933102] [80s80s] clearAddPlayTrack url: http://streams.90s90s.de/pop/mp3-192/volumio Sep 06 06:05:33 volumio volumio[926]: info: [1757127933102] [80s80s] getContentOfUrl started with url http://iris-90s90s.loverad.io/flow.json?station=141&count=2 Sep 06 06:05:33 volumio volumio[926]: info: [ASDebug] CurState: stop PrevState: stop Sep 06 06:05:33 volumio volumio[926]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Sep 06 06:05:33 volumio volumio[926]: info: Sep 06 06:05:33 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:33 volumio volumio[926]: info: sendMpdCommand stop took 31 milliseconds Sep 06 06:05:33 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:33 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:33 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:33 volumio volumio[926]: info: CoreStateMachine::pushState Sep 06 06:05:33 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:33 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 06 06:05:33 volumio volumio[926]: info: CoreCommandRouter::volumioPushState Sep 06 06:05:33 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:33 volumio volumio[926]: verbose: STATE SERVICE {"status":"stop","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is3-ssl.mzstatic.com/image/thumb/Music125/v4/4f/fe/e6/4ffee641-1876-29c6-2307-0dcdc660cd9a/source/600x600bb.jpg","name":"Red Hot Chili Peppers - Scar Tissue","title":"Scar Tissue","artist":"90s90s Hits","album":"","streaming":true,"disableUiControls":true,"duration":"206","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Sep 06 06:05:33 volumio volumio[926]: verbose: CURRENT POSITION 0 Sep 06 06:05:33 volumio volumio[926]: info: CoreStateMachine::syncState stateService stop Sep 06 06:05:33 volumio volumio[926]: info: CoreStateMachine::syncState currentStatus stop Sep 06 06:05:33 volumio volumio[926]: info: CoreStateMachine::pushState Sep 06 06:05:33 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:33 volumio volumio[926]: info: CoreCommandRouter::volumioPushState Sep 06 06:05:33 volumio volumio[926]: info: No code Sep 06 06:05:33 volumio volumio[926]: info: CoreStateMachine::pushState Sep 06 06:05:33 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:33 volumio volumio[926]: info: CoreCommandRouter::volumioPushState Sep 06 06:05:33 volumio volumio[926]: info: Sep 06 06:05:33 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:33 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:33 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:33 volumio volumio[926]: info: Sep 06 06:05:33 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:33 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:33 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:33 volumio volumio[926]: info: [ASDebug] CurState: stop PrevState: stop Sep 06 06:05:33 volumio volumio[926]: info: [ASDebug] CurState: stop PrevState: stop Sep 06 06:05:33 volumio volumio[926]: info: [ASDebug] CurState: stop PrevState: stop Sep 06 06:05:33 volumio volumio[926]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Sep 06 06:05:33 volumio volumio[926]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Sep 06 06:05:33 volumio volumio[926]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Sep 06 06:05:33 volumio volumio[926]: info: sendMpdCommand status took 35 milliseconds Sep 06 06:05:33 volumio volumio[926]: info: sendMpdCommand status took 13 milliseconds Sep 06 06:05:33 volumio volumio[926]: info: sendMpdCommand status took 12 milliseconds Sep 06 06:05:33 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:33 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:33 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:33 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:33 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:33 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:33 volumio volumio[926]: info: sendMpdCommand playlistinfo took 2 milliseconds Sep 06 06:05:33 volumio volumio[926]: info: sendMpdCommand playlistinfo took 3 milliseconds Sep 06 06:05:33 volumio volumio[926]: info: sendMpdCommand playlistinfo took 3 milliseconds Sep 06 06:05:33 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:33 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:33 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:33 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:33 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:33 volumio volumio[926]: info: CoreStateMachine::pushState Sep 06 06:05:33 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:33 volumio volumio[926]: info: CoreCommandRouter::volumioPushState Sep 06 06:05:33 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:33 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:33 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:33 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:33 volumio volumio[926]: info: CoreStateMachine::pushState Sep 06 06:05:33 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:33 volumio volumio[926]: info: CoreCommandRouter::volumioPushState Sep 06 06:05:33 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:33 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:33 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:33 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:33 volumio volumio[926]: info: CoreStateMachine::pushState Sep 06 06:05:33 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:33 volumio volumio[926]: info: CoreCommandRouter::volumioPushState Sep 06 06:05:33 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:33 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:33 volumio volumio[926]: info: ------------------------------ 59ms Sep 06 06:05:33 volumio volumio[926]: info: ------------------------------ 38ms Sep 06 06:05:33 volumio volumio[926]: info: ------------------------------ 37ms Sep 06 06:05:33 volumio volumio[926]: info: [ASDebug] CurState: stop PrevState: stop Sep 06 06:05:33 volumio volumio[926]: info: [ASDebug] CurState: stop PrevState: stop Sep 06 06:05:33 volumio volumio[926]: info: [ASDebug] CurState: stop PrevState: stop Sep 06 06:05:33 volumio volumio[926]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Sep 06 06:05:33 volumio volumio[926]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Sep 06 06:05:33 volumio volumio[926]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Sep 06 06:05:33 volumio volumio[926]: info: [1757127933361] [80s80s] received new event containing 2 songs. Sep 06 06:05:33 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand stop Sep 06 06:05:33 volumio volumio[926]: info: sendMpdCommand stop took 1 milliseconds Sep 06 06:05:33 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand clear Sep 06 06:05:33 volumio volumio[926]: info: Sep 06 06:05:33 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:33 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:33 volumio volumio[926]: info: sendMpdCommand clear took 1 milliseconds Sep 06 06:05:33 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand consume 1 Sep 06 06:05:33 volumio volumio[926]: info: Sep 06 06:05:33 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:33 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:33 volumio volumio[926]: info: Sep 06 06:05:33 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:33 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:33 volumio volumio[926]: error: updateQueue error: null Sep 06 06:05:33 volumio volumio[926]: error: updateQueue error: null Sep 06 06:05:33 volumio volumio[926]: error: updateQueue error: null Sep 06 06:05:33 volumio volumio[926]: info: ------------------------------ 5ms Sep 06 06:05:33 volumio volumio[926]: info: sendMpdCommand consume 1 took 4 milliseconds Sep 06 06:05:33 volumio volumio[926]: info: ------------------------------ 4ms Sep 06 06:05:33 volumio volumio[926]: info: ------------------------------ 3ms Sep 06 06:05:33 volumio volumio[926]: info: [1757127933371] [80s80s] adding url: http://streams.90s90s.de/pop/mp3-192/volumio Sep 06 06:05:33 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand add "http://streams.90s90s.de/pop/mp3-192/volumio" Sep 06 06:05:33 volumio volumio[926]: info: Sep 06 06:05:33 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:33 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:33 volumio volumio[926]: info: sendMpdCommand add "http://streams.90s90s.de/pop/mp3-192/volumio" took 2 milliseconds Sep 06 06:05:33 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand play Sep 06 06:05:33 volumio volumio[926]: info: Sep 06 06:05:33 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:33 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:33 volumio volumio[926]: info: Sep 06 06:05:33 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:33 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:33 volumio volumio[926]: info: ------------------------------ 8ms Sep 06 06:05:33 volumio volumio[926]: info: sendMpdCommand play took 5 milliseconds Sep 06 06:05:33 volumio volumio[926]: info: ------------------------------ 4ms Sep 06 06:05:33 volumio volumio[926]: info: ------------------------------ 3ms Sep 06 06:05:33 volumio volumio[926]: info: [1757127933381] [80s80s] Pushing the next song state: Red Hot Chili Peppers - Scar Tissue Sep 06 06:05:33 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:33 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:33 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:33 volumio volumio[926]: verbose: STATE SERVICE {"status":"play","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is3-ssl.mzstatic.com/image/thumb/Music125/v4/4f/fe/e6/4ffee641-1876-29c6-2307-0dcdc660cd9a/source/600x600bb.jpg","name":"Red Hot Chili Peppers - Scar Tissue","title":"Scar Tissue","artist":"90s90s Hits","album":"","streaming":true,"disableUiControls":true,"duration":"206","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Sep 06 06:05:33 volumio volumio[926]: verbose: CURRENT POSITION 0 Sep 06 06:05:33 volumio volumio[926]: info: CoreStateMachine::syncState stateService play Sep 06 06:05:33 volumio volumio[926]: info: CoreStateMachine::syncState currentStatus stop Sep 06 06:05:33 volumio volumio[926]: info: [1757127933383] [80s80s] PlayNextTrack API delay: 30 Sep 06 06:05:33 volumio volumio[926]: info: [1757127933385] [80s80s] Setting timer to: 206000 milliseconds. Sep 06 06:05:34 volumio volumio[926]: info: Sep 06 06:05:34 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:34 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:34 volumio volumio[926]: info: Sep 06 06:05:34 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:34 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:34 volumio volumio[926]: info: Sep 06 06:05:34 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:34 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:34 volumio volumio[926]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Sep 06 06:05:34 volumio volumio[926]: info: FusionDsp - ---- read samplerate from file: 44100 Sep 06 06:05:34 volumio volumio[926]: info: FusionDsp - If filter freq >samplerate/2 then disable it Sep 06 06:05:34 volumio volumio[926]: info: Sep 06 06:05:34 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:34 volumio volumio[926]: info: sendMpdCommand status took 20 milliseconds Sep 06 06:05:34 volumio volumio[926]: info: sendMpdCommand status took 20 milliseconds Sep 06 06:05:34 volumio volumio[926]: info: sendMpdCommand status took 19 milliseconds Sep 06 06:05:34 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:34 volumio volumio[926]: info: Sep 06 06:05:34 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:34 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:34 volumio volumio[926]: info: Sep 06 06:05:34 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:34 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:34 volumio volumio[926]: info: sendMpdCommand status took 6 milliseconds Sep 06 06:05:34 volumio volumio[926]: info: sendMpdCommand playlistinfo took 7 milliseconds Sep 06 06:05:34 volumio volumio[926]: info: sendMpdCommand playlistinfo took 7 milliseconds Sep 06 06:05:34 volumio volumio[926]: info: sendMpdCommand playlistinfo took 6 milliseconds Sep 06 06:05:34 volumio volumio[926]: info: sendMpdCommand status took 4 milliseconds Sep 06 06:05:34 volumio volumio[926]: info: sendMpdCommand status took 4 milliseconds Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:34 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:34 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:34 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:34 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:34 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:34 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:34 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:34 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:34 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:34 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:34 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:34 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:34 volumio volumio[926]: info: ------------------------------ 40ms Sep 06 06:05:34 volumio volumio[926]: info: ------------------------------ 39ms Sep 06 06:05:34 volumio volumio[926]: info: ------------------------------ 37ms Sep 06 06:05:34 volumio volumio[926]: error: FusionDsp - WebSocket error: [object Object] Sep 06 06:05:34 volumio volumio[926]: info: sendMpdCommand playlistinfo took 9 milliseconds Sep 06 06:05:34 volumio volumio[926]: info: sendMpdCommand playlistinfo took 7 milliseconds Sep 06 06:05:34 volumio volumio[926]: info: sendMpdCommand playlistinfo took 7 milliseconds Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:34 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:34 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:34 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:34 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:34 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:34 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:34 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:34 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:34 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:34 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:34 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:34 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:34 volumio volumio[926]: info: ------------------------------ 26ms Sep 06 06:05:34 volumio volumio[926]: info: ------------------------------ 22ms Sep 06 06:05:34 volumio volumio[926]: info: ------------------------------ 20ms Sep 06 06:05:34 volumio volumio[926]: info: Sep 06 06:05:34 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:34 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:34 volumio volumio[926]: info: Sep 06 06:05:34 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:34 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:34 volumio volumio[926]: info: Sep 06 06:05:34 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:34 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:34 volumio volumio[926]: info: Sep 06 06:05:34 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:34 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:34 volumio volumio[926]: info: Sep 06 06:05:34 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:34 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:34 volumio volumio[926]: info: Sep 06 06:05:34 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:34 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:34 volumio volumio[926]: info: Sep 06 06:05:34 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:34 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:34 volumio volumio[926]: info: Sep 06 06:05:34 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:34 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:34 volumio volumio[926]: info: ------------------------------ 12ms Sep 06 06:05:34 volumio volumio[926]: info: sendMpdCommand status took 8 milliseconds Sep 06 06:05:34 volumio volumio[926]: info: ------------------------------ 9ms Sep 06 06:05:34 volumio volumio[926]: info: sendMpdCommand status took 7 milliseconds Sep 06 06:05:34 volumio volumio[926]: info: ------------------------------ 6ms Sep 06 06:05:34 volumio volumio[926]: info: sendMpdCommand status took 4 milliseconds Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:34 volumio volumio[926]: info: Sep 06 06:05:34 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:34 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:34 volumio volumio[926]: info: Sep 06 06:05:34 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:34 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:34 volumio volumio[926]: info: Sep 06 06:05:34 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:34 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:34 volumio volumio[926]: info: Sep 06 06:05:34 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:34 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:34 volumio volumio[926]: info: ------------------------------ 16ms Sep 06 06:05:34 volumio volumio[926]: info: sendMpdCommand status took 14 milliseconds Sep 06 06:05:34 volumio volumio[926]: info: sendMpdCommand playlistinfo took 13 milliseconds Sep 06 06:05:34 volumio volumio[926]: info: sendMpdCommand playlistinfo took 12 milliseconds Sep 06 06:05:34 volumio volumio[926]: info: sendMpdCommand playlistinfo took 12 milliseconds Sep 06 06:05:34 volumio volumio[926]: info: ------------------------------ 12ms Sep 06 06:05:34 volumio volumio[926]: info: sendMpdCommand status took 7 milliseconds Sep 06 06:05:34 volumio volumio[926]: info: ------------------------------ 6ms Sep 06 06:05:34 volumio volumio[926]: info: sendMpdCommand status took 6 milliseconds Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:34 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:34 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:34 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:34 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:34 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:34 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:34 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:34 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:34 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:34 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:34 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:34 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:34 volumio volumio[926]: info: ------------------------------ 35ms Sep 06 06:05:34 volumio volumio[926]: info: ------------------------------ 32ms Sep 06 06:05:34 volumio volumio[926]: info: ------------------------------ 29ms Sep 06 06:05:34 volumio volumio[926]: info: sendMpdCommand playlistinfo took 7 milliseconds Sep 06 06:05:34 volumio volumio[926]: info: sendMpdCommand playlistinfo took 6 milliseconds Sep 06 06:05:34 volumio volumio[926]: info: sendMpdCommand playlistinfo took 6 milliseconds Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:34 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:34 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:34 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:34 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:34 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:34 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:34 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:34 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:34 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:34 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:34 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:34 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:34 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:34 volumio volumio[926]: info: ------------------------------ 42ms Sep 06 06:05:34 volumio volumio[926]: info: ------------------------------ 36ms Sep 06 06:05:34 volumio volumio[926]: info: ------------------------------ 32ms Sep 06 06:05:36 volumio volumio[926]: info: CoreCommandRouter::volumioGetState Sep 06 06:05:36 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:36 volumio volumio[926]: info: Listing playlists Sep 06 06:05:36 volumio volumio[926]: info: Listing playlists Sep 06 06:05:42 volumio go-librespot[15003]: time="2025-09-06T06:05:42+03:00" level=trace msg="sent dealer ping" Sep 06 06:05:43 volumio go-librespot[15003]: time="2025-09-06T06:05:43+03:00" level=trace msg="received dealer pong" Sep 06 06:05:46 volumio volumio[926]: info: CoreCommandRouter::volumioGetState Sep 06 06:05:46 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:56 volumio volumio[926]: info: CoreCommandRouter::volumioGetState Sep 06 06:05:56 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:56 volumio volumio[926]: info: Listing playlists Sep 06 06:05:56 volumio volumio[926]: info: Preload queue cleared Sep 06 06:05:56 volumio volumio[926]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 06 06:05:56 volumio volumio[926]: info: CoreStateMachine::ClearQueue Sep 06 06:05:56 volumio volumio[926]: info: CoreStateMachine::stop Sep 06 06:05:56 volumio volumio[926]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 06 06:05:56 volumio volumio[926]: info: CoreStateMachine::stPlaybackTimer Sep 06 06:05:56 volumio volumio[926]: info: CoreStateMachine::updateTrackBlock Sep 06 06:05:56 volumio volumio[926]: info: CorePlayQueue::getTrackBlock Sep 06 06:05:56 volumio volumio[926]: info: CoreStateMachine::pushState Sep 06 06:05:56 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:56 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 06 06:05:56 volumio volumio[926]: info: CoreCommandRouter::volumioPushState Sep 06 06:05:56 volumio volumio[926]: info: CoreStateMachine::serviceStop Sep 06 06:05:56 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:56 volumio volumio[926]: info: CoreCommandRouter::serviceStop Sep 06 06:05:56 volumio volumio[926]: info: ControllerMpd::stop Sep 06 06:05:56 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand stop Sep 06 06:05:56 volumio volumio[926]: info: CorePlayQueue::clearPlayQueue Sep 06 06:05:56 volumio volumio[926]: info: CorePlayQueue::saveQueue Sep 06 06:05:56 volumio volumio[926]: info: CoreCommandRouter::volumioPushQueue Sep 06 06:05:56 volumio volumio[926]: info: CoreStateMachine::addQueueItems Sep 06 06:05:56 volumio volumio[926]: info: CorePlayQueue::addQueueItems Sep 06 06:05:56 volumio volumio[926]: info: Preload queue cleared Sep 06 06:05:56 volumio volumio[926]: info: Adding Item to queue: webnineties/6 Sep 06 06:05:56 volumio volumio[926]: info: Exploding uri webnineties/6 in service 80s80s Sep 06 06:05:56 volumio volumio[926]: info: [1757127956648] [80s80s] explodeUri: webnineties/6 Sep 06 06:05:56 volumio volumio[926]: info: CoreCommandRouter::volumioPushQueue Sep 06 06:05:56 volumio volumio[926]: info: CorePlayQueue::saveQueue Sep 06 06:05:56 volumio volumio[926]: info: CoreStateMachine::updateTrackBlock Sep 06 06:05:56 volumio volumio[926]: info: CorePlayQueue::getTrackBlock Sep 06 06:05:56 volumio volumio[926]: info: CoreCommandRouter::volumioPlay Sep 06 06:05:56 volumio volumio[926]: info: CoreStateMachine::play index 0 Sep 06 06:05:56 volumio volumio[926]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 06 06:05:56 volumio volumio[926]: info: CoreStateMachine::stop Sep 06 06:05:56 volumio volumio[926]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 06 06:05:56 volumio volumio[926]: info: CoreStateMachine::play index undefined Sep 06 06:05:56 volumio volumio[926]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 06 06:05:56 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:56 volumio volumio[926]: info: CoreStateMachine::startPlaybackTimer Sep 06 06:05:56 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:56 volumio volumio[926]: info: [1757127956662] [80s80s] clearAddPlayTrack url: http://streams.90s90s.de/rnb/mp3-192/volumio Sep 06 06:05:56 volumio volumio[926]: info: [1757127956662] [80s80s] getContentOfUrl started with url http://iris-90s90s.loverad.io/flow.json?station=266&count=2 Sep 06 06:05:56 volumio volumio[926]: info: [ASDebug] CurState: stop PrevState: stop Sep 06 06:05:56 volumio volumio[926]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Sep 06 06:05:56 volumio volumio[926]: info: Sep 06 06:05:56 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:56 volumio volumio[926]: info: sendMpdCommand stop took 28 milliseconds Sep 06 06:05:56 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:56 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:56 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:56 volumio volumio[926]: info: CoreStateMachine::pushState Sep 06 06:05:56 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:56 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 06 06:05:56 volumio volumio[926]: info: CoreCommandRouter::volumioPushState Sep 06 06:05:56 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:56 volumio volumio[926]: verbose: STATE SERVICE {"status":"stop","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is3-ssl.mzstatic.com/image/thumb/Music125/v4/4f/fe/e6/4ffee641-1876-29c6-2307-0dcdc660cd9a/source/600x600bb.jpg","name":"Red Hot Chili Peppers - Scar Tissue","title":"Scar Tissue","artist":"90s90s Hits","album":"","streaming":true,"disableUiControls":true,"duration":"206","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Sep 06 06:05:56 volumio volumio[926]: verbose: CURRENT POSITION 0 Sep 06 06:05:56 volumio volumio[926]: info: CoreStateMachine::syncState stateService stop Sep 06 06:05:56 volumio volumio[926]: info: CoreStateMachine::syncState currentStatus stop Sep 06 06:05:56 volumio volumio[926]: info: CoreStateMachine::pushState Sep 06 06:05:56 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:56 volumio volumio[926]: info: CoreCommandRouter::volumioPushState Sep 06 06:05:56 volumio volumio[926]: info: No code Sep 06 06:05:56 volumio volumio[926]: info: CoreStateMachine::pushState Sep 06 06:05:56 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:56 volumio volumio[926]: info: CoreCommandRouter::volumioPushState Sep 06 06:05:56 volumio volumio[926]: info: Sep 06 06:05:56 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:56 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:56 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:56 volumio volumio[926]: info: Sep 06 06:05:56 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:56 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:56 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:56 volumio volumio[926]: info: [ASDebug] CurState: stop PrevState: stop Sep 06 06:05:56 volumio volumio[926]: info: [ASDebug] CurState: stop PrevState: stop Sep 06 06:05:56 volumio volumio[926]: info: [ASDebug] CurState: stop PrevState: stop Sep 06 06:05:56 volumio volumio[926]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Sep 06 06:05:56 volumio volumio[926]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Sep 06 06:05:56 volumio volumio[926]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Sep 06 06:05:56 volumio volumio[926]: info: sendMpdCommand status took 33 milliseconds Sep 06 06:05:56 volumio volumio[926]: info: sendMpdCommand status took 13 milliseconds Sep 06 06:05:56 volumio volumio[926]: info: sendMpdCommand status took 11 milliseconds Sep 06 06:05:56 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:56 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:56 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:56 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:56 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:56 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:56 volumio volumio[926]: info: sendMpdCommand playlistinfo took 3 milliseconds Sep 06 06:05:56 volumio volumio[926]: info: sendMpdCommand playlistinfo took 3 milliseconds Sep 06 06:05:56 volumio volumio[926]: info: sendMpdCommand playlistinfo took 3 milliseconds Sep 06 06:05:56 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:56 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:56 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:56 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:56 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:56 volumio volumio[926]: info: CoreStateMachine::pushState Sep 06 06:05:56 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:56 volumio volumio[926]: info: CoreCommandRouter::volumioPushState Sep 06 06:05:56 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:56 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:56 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:56 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:56 volumio volumio[926]: info: CoreStateMachine::pushState Sep 06 06:05:56 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:56 volumio volumio[926]: info: CoreCommandRouter::volumioPushState Sep 06 06:05:56 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:56 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:56 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:56 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:56 volumio volumio[926]: info: CoreStateMachine::pushState Sep 06 06:05:56 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:56 volumio volumio[926]: info: CoreCommandRouter::volumioPushState Sep 06 06:05:56 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:56 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:56 volumio volumio[926]: info: ------------------------------ 57ms Sep 06 06:05:56 volumio volumio[926]: info: ------------------------------ 35ms Sep 06 06:05:56 volumio volumio[926]: info: ------------------------------ 35ms Sep 06 06:05:56 volumio volumio[926]: info: [ASDebug] CurState: stop PrevState: stop Sep 06 06:05:56 volumio volumio[926]: info: [ASDebug] CurState: stop PrevState: stop Sep 06 06:05:56 volumio volumio[926]: info: [ASDebug] CurState: stop PrevState: stop Sep 06 06:05:56 volumio volumio[926]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Sep 06 06:05:56 volumio volumio[926]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Sep 06 06:05:56 volumio volumio[926]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Sep 06 06:05:56 volumio volumio[926]: info: [1757127956886] [80s80s] received new event containing 2 songs. Sep 06 06:05:56 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand stop Sep 06 06:05:56 volumio volumio[926]: info: sendMpdCommand stop took 1 milliseconds Sep 06 06:05:56 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand clear Sep 06 06:05:56 volumio volumio[926]: info: Sep 06 06:05:56 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:56 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:56 volumio volumio[926]: info: sendMpdCommand clear took 2 milliseconds Sep 06 06:05:56 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand consume 1 Sep 06 06:05:56 volumio volumio[926]: info: Sep 06 06:05:56 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:56 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:56 volumio volumio[926]: info: Sep 06 06:05:56 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:56 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:56 volumio volumio[926]: error: updateQueue error: null Sep 06 06:05:56 volumio volumio[926]: error: updateQueue error: null Sep 06 06:05:56 volumio volumio[926]: error: updateQueue error: null Sep 06 06:05:56 volumio volumio[926]: info: ------------------------------ 6ms Sep 06 06:05:56 volumio volumio[926]: info: sendMpdCommand consume 1 took 5 milliseconds Sep 06 06:05:56 volumio volumio[926]: info: ------------------------------ 4ms Sep 06 06:05:56 volumio volumio[926]: info: ------------------------------ 3ms Sep 06 06:05:56 volumio volumio[926]: info: [1757127956897] [80s80s] adding url: http://streams.90s90s.de/rnb/mp3-192/volumio Sep 06 06:05:56 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand add "http://streams.90s90s.de/rnb/mp3-192/volumio" Sep 06 06:05:56 volumio volumio[926]: info: Sep 06 06:05:56 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:56 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:56 volumio volumio[926]: info: sendMpdCommand add "http://streams.90s90s.de/rnb/mp3-192/volumio" took 2 milliseconds Sep 06 06:05:56 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand play Sep 06 06:05:56 volumio volumio[926]: info: Sep 06 06:05:56 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:56 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:56 volumio volumio[926]: info: Sep 06 06:05:56 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:56 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:56 volumio volumio[926]: info: ------------------------------ 20ms Sep 06 06:05:56 volumio volumio[926]: info: sendMpdCommand play took 16 milliseconds Sep 06 06:05:56 volumio volumio[926]: info: ------------------------------ 14ms Sep 06 06:05:56 volumio volumio[926]: info: ------------------------------ 13ms Sep 06 06:05:56 volumio volumio[926]: info: [1757127956919] [80s80s] Pushing the next song state: LL COOL J - Hey Lover (feat. Boyz II Men) Sep 06 06:05:56 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:56 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:56 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:56 volumio volumio[926]: verbose: STATE SERVICE {"status":"play","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is4-ssl.mzstatic.com/image/thumb/Music124/v4/c5/1f/f8/c51ff8be-95b5-87ac-e543-3c76d8d61a4b/source/600x600bb.jpg","name":"LL COOL J - Hey Lover (feat. Boyz II Men)","title":"Hey Lover (feat. Boyz II Men)","artist":"90s90s Black & RnB","album":"","streaming":true,"disableUiControls":true,"duration":"276","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Sep 06 06:05:56 volumio volumio[926]: verbose: CURRENT POSITION 0 Sep 06 06:05:56 volumio volumio[926]: info: CoreStateMachine::syncState stateService play Sep 06 06:05:56 volumio volumio[926]: info: CoreStateMachine::syncState currentStatus stop Sep 06 06:05:56 volumio volumio[926]: info: [1757127956921] [80s80s] PlayNextTrack API delay: 30 Sep 06 06:05:56 volumio volumio[926]: info: [1757127956923] [80s80s] Setting timer to: 276000 milliseconds. Sep 06 06:05:57 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:57 volumio volumio[926]: info: CorePlayQueue::getTrack 1 Sep 06 06:05:57 volumio volumio[926]: info: Sep 06 06:05:57 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:57 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:57 volumio volumio[926]: info: Sep 06 06:05:57 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:57 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:57 volumio volumio[926]: info: Sep 06 06:05:57 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:57 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:57 volumio volumio[926]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Sep 06 06:05:57 volumio volumio[926]: info: FusionDsp - ---- read samplerate from file: 44100 Sep 06 06:05:57 volumio volumio[926]: info: FusionDsp - If filter freq >samplerate/2 then disable it Sep 06 06:05:57 volumio volumio[926]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Sep 06 06:05:57 volumio volumio[926]: info: FusionDsp - ---- read samplerate from file: 44100 Sep 06 06:05:57 volumio volumio[926]: info: FusionDsp - If filter freq >samplerate/2 then disable it Sep 06 06:05:57 volumio volumio[926]: info: Sep 06 06:05:57 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:57 volumio volumio[926]: info: sendMpdCommand status took 26 milliseconds Sep 06 06:05:57 volumio volumio[926]: info: sendMpdCommand status took 24 milliseconds Sep 06 06:05:57 volumio volumio[926]: info: sendMpdCommand status took 23 milliseconds Sep 06 06:05:57 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:57 volumio volumio[926]: info: Sep 06 06:05:57 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:57 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:57 volumio volumio[926]: info: Sep 06 06:05:57 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:57 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:57 volumio volumio[926]: info: sendMpdCommand status took 6 milliseconds Sep 06 06:05:57 volumio volumio[926]: info: sendMpdCommand playlistinfo took 6 milliseconds Sep 06 06:05:57 volumio volumio[926]: info: sendMpdCommand playlistinfo took 6 milliseconds Sep 06 06:05:57 volumio volumio[926]: info: sendMpdCommand playlistinfo took 6 milliseconds Sep 06 06:05:57 volumio volumio[926]: info: sendMpdCommand status took 5 milliseconds Sep 06 06:05:57 volumio volumio[926]: info: sendMpdCommand status took 3 milliseconds Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:57 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:57 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:57 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:57 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:57 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:57 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:57 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:57 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:57 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:57 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:57 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:57 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:57 volumio volumio[926]: info: ------------------------------ 42ms Sep 06 06:05:57 volumio volumio[926]: info: ------------------------------ 40ms Sep 06 06:05:57 volumio volumio[926]: info: ------------------------------ 39ms Sep 06 06:05:57 volumio volumio[926]: error: FusionDsp - WebSocket error: [object Object] Sep 06 06:05:57 volumio volumio[926]: error: FusionDsp - WebSocket error: [object Object] Sep 06 06:05:57 volumio volumio[926]: info: sendMpdCommand playlistinfo took 8 milliseconds Sep 06 06:05:57 volumio volumio[926]: info: sendMpdCommand playlistinfo took 8 milliseconds Sep 06 06:05:57 volumio volumio[926]: info: sendMpdCommand playlistinfo took 8 milliseconds Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:57 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:57 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:57 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:57 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:57 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:57 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:57 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:57 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:57 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:57 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:57 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:57 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:57 volumio volumio[926]: info: ------------------------------ 26ms Sep 06 06:05:57 volumio volumio[926]: info: ------------------------------ 23ms Sep 06 06:05:57 volumio volumio[926]: info: ------------------------------ 21ms Sep 06 06:05:57 volumio volumio[926]: info: Sep 06 06:05:57 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:57 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:57 volumio volumio[926]: info: Sep 06 06:05:57 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:57 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:57 volumio volumio[926]: info: Sep 06 06:05:57 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:57 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:57 volumio volumio[926]: info: Sep 06 06:05:57 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:57 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:57 volumio volumio[926]: info: Sep 06 06:05:57 volumio volumio[926]: ---------------------------- MPD announces system playlist update Sep 06 06:05:57 volumio volumio[926]: info: Ignoring MPD Status Update Sep 06 06:05:57 volumio volumio[926]: info: Sep 06 06:05:57 volumio volumio[926]: ---------------------------- MPD announces state update: player Sep 06 06:05:57 volumio volumio[926]: info: ControllerMpd::getState Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand status Sep 06 06:05:57 volumio volumio[926]: info: ------------------------------ 7ms Sep 06 06:05:57 volumio volumio[926]: info: sendMpdCommand status took 7 milliseconds Sep 06 06:05:57 volumio volumio[926]: info: ------------------------------ 6ms Sep 06 06:05:57 volumio volumio[926]: info: sendMpdCommand status took 5 milliseconds Sep 06 06:05:57 volumio volumio[926]: info: ------------------------------ 5ms Sep 06 06:05:57 volumio volumio[926]: info: sendMpdCommand status took 3 milliseconds Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::parseState Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 06:05:57 volumio volumio[926]: info: sendMpdCommand playlistinfo took 2 milliseconds Sep 06 06:05:57 volumio volumio[926]: info: sendMpdCommand playlistinfo took 2 milliseconds Sep 06 06:05:57 volumio volumio[926]: info: sendMpdCommand playlistinfo took 2 milliseconds Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:57 volumio volumio[926]: verbose: ControllerMpd::parseTrackInfo Sep 06 06:05:57 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:57 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:57 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:57 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:57 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:57 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:57 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:57 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:57 volumio volumio[926]: info: ControllerMpd::pushState Sep 06 06:05:57 volumio volumio[926]: info: CoreCommandRouter::servicePushState Sep 06 06:05:57 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:05:57 volumio volumio[926]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Sep 06 06:05:57 volumio volumio[926]: info: ------------------------------ 15ms Sep 06 06:05:57 volumio volumio[926]: info: ------------------------------ 12ms Sep 06 06:05:57 volumio volumio[926]: info: ------------------------------ 11ms Sep 06 06:06:00 volumio volumio[926]: info: VolumeController::SetAlsaVolume14 Sep 06 06:06:00 volumio volumio[926]: info: CoreStateMachine::pushState Sep 06 06:06:00 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:06:00 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 06 06:06:00 volumio volumio[926]: info: CoreCommandRouter::volumioPushState Sep 06 06:06:00 volumio volumio[926]: info: [ASDebug] CurState: play PrevState: stop Sep 06 06:06:00 volumio volumio[926]: info: [ASDebug] Togle GPIO: ON Sep 06 06:06:00 volumio volumio[926]: SPOTIFY: RECEIVED VOLUMIO VOLUME 14 Sep 06 06:06:00 volumio volumio[926]: SPOTIFY: SPOTIFY VOLUME 10 Sep 06 06:06:00 volumio volumio[926]: SPOTIFY: VOLUMIO VOLUME 14 Sep 06 06:06:00 volumio volumio[926]: SPOTIFY: DELTA VOLUME ENOUGH: true Sep 06 06:06:00 volumio volumio[926]: info: Setting Spotify Volume from Volumio: 14 Sep 06 06:06:01 volumio volumio[926]: info: VolumeController::SetAlsaVolume24 Sep 06 06:06:01 volumio volumio[926]: info: CoreStateMachine::pushState Sep 06 06:06:01 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:06:01 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 06 06:06:01 volumio volumio[926]: info: CoreCommandRouter::volumioPushState Sep 06 06:06:01 volumio volumio[926]: info: [ASDebug] CurState: play PrevState: play Sep 06 06:06:01 volumio volumio[926]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Sep 06 06:06:01 volumio volumio[926]: SPOTIFY: SPOTIFY VOLUME 14 Sep 06 06:06:01 volumio volumio[926]: SPOTIFY: VOLUMIO VOLUME 24 Sep 06 06:06:01 volumio volumio[926]: SPOTIFY: DELTA VOLUME ENOUGH: true Sep 06 06:06:01 volumio volumio[926]: info: Setting Spotify Volume from Volumio: 24 Sep 06 06:06:02 volumio volumio[926]: SPOTIFY: SETTING SPOTIFY VOLUME 24 Sep 06 06:06:02 volumio volumio[926]: info: Sending Spotify command with payload to local API: /player/volume Sep 06 06:06:02 volumio go-librespot[15003]: time="2025-09-06T06:06:02+03:00" level=debug msg="update volume requested to 15728/65535" Sep 06 06:06:02 volumio go-librespot[15003]: time="2025-09-06T06:06:02+03:00" level=debug msg="put connect state because VOLUME_CHANGED" Sep 06 06:06:02 volumio go-librespot[15003]: time="2025-09-06T06:06:02+03:00" level=trace msg="emitting websocket event: volume" Sep 06 06:06:02 volumio volumio[926]: SPOTIFY: received: {"type":"volume","data":{"value":24,"max":100}} Sep 06 06:06:02 volumio volumio[926]: SPOTIFY: RECEIVED SPOTIFY VOLUME 24 Sep 06 06:06:02 volumio volumio[926]: SPOTIFY: received: {"type":"volume","data":{"value":24,"max":100}} Sep 06 06:06:02 volumio volumio[926]: SPOTIFY: RECEIVED SPOTIFY VOLUME 24 Sep 06 06:06:06 volumio volumio[926]: info: CoreCommandRouter::volumioGetState Sep 06 06:06:06 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:06:12 volumio go-librespot[15003]: time="2025-09-06T06:06:12+03:00" level=trace msg="sent dealer ping" Sep 06 06:06:13 volumio go-librespot[15003]: time="2025-09-06T06:06:13+03:00" level=trace msg="received dealer pong" Sep 06 06:06:15 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 06 06:06:15 volumio volumio[926]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Sep 06 06:06:15 volumio volumio[926]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 06 06:06:15 volumio volumio[926]: info: FusionDsp - Sep 06 06:06:16 volumio volumio[926]: info: FusionDsp - undefined Sep 06 06:06:16 volumio volumio[926]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 06 06:06:16 volumio volumio[926]: info: FusionDsp - Sep 06 06:06:16 volumio volumio[926]: info: FusionDsp - undefined Sep 06 06:06:16 volumio volumio[926]: info: CoreCommandRouter::volumioGetState Sep 06 06:06:16 volumio volumio[926]: info: CorePlayQueue::getTrack 0 Sep 06 06:06:16 volumio volumio[926]: info: Listing playlists Sep 06 06:06:16 volumio volumio[926]: info: Listing playlists Sep 06 06:06:22 volumio volumio[926]: info: Starting Uninstall of plugin audio_interface - fusiondsp Sep 06 06:06:22 volumio volumio[926]: info: Uninstalling plugin fusiondsp Sep 06 06:06:22 volumio volumio[926]: info: FusionDsp - Stopping FusionDsp service Sep 06 06:06:22 volumio volumio[926]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 06 06:06:23 volumio volumio[926]: TypeError: Cannot read property 'stop' of null Sep 06 06:06:23 volumio volumio[926]: at FusionDsp.onStop (/data/plugins/audio_interface/fusiondsp/index.js:109:23) Sep 06 06:06:23 volumio volumio[926]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30) Sep 06 06:06:23 volumio volumio[926]: at PluginManager.unInstallPlugin (/volumio/app/pluginmanager.js:1449:10) Sep 06 06:06:23 volumio volumio[926]: at CoreCommandRouter.unInstallPlugin (/volumio/app/index.js:1484:22) Sep 06 06:06:23 volumio volumio[926]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1260:45) Sep 06 06:06:23 volumio volumio[926]: at Socket.emit (events.js:315:20) Sep 06 06:06:23 volumio volumio[926]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Sep 06 06:06:23 volumio volumio[926]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Sep 06 06:06:23 volumio volumio[926]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 06 06:06:23 volumio sudo[2576]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-06 06:05 Sep 06 06:06:23 volumio sudo[2576]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="29866754e5f1d7e4d0f581c10d9f22852f6f21db" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:25:36 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="cf6e14681b2ecbbdc9a62186b0f3114c"