-- Logs begin at Sun 2025-06-15 17:57:21 UTC, end at Sun 2025-06-15 18:09:16 UTC. -- Jun 15 18:08:07 volumio volumio[4225]: info: CoreCommandRouter::volumioNext Jun 15 18:08:07 volumio volumio[4225]: info: CoreStateMachine::next Jun 15 18:08:07 volumio volumio[4225]: info: Spotify next Jun 15 18:08:07 volumio volumio[994]: [Vollibrespot] : Event: Next { track_id: SpotifyId { id: 273690301210807357512555782909957203329, audio_type: Track } } Jun 15 18:08:07 volumio volumio[994]: [Vollibrespot] : Event: TrackChanged { old_track_id: SpotifyId { id: 273690301210807357512555782909957203329, audio_type: Track }, track_id: SpotifyId { id: 273690301210807357512555782909957203329, audio_type: Track } } Jun 15 18:08:07 volumio volumio[4225]: [SpotifyConnect] Virtue Jun 15 18:08:07 volumio volumio[4225]: info: [1750010887587] ControllerSpotify::pushState Jun 15 18:08:07 volumio volumio[4225]: info: CoreCommandRouter::servicePushState Jun 15 18:08:07 volumio volumio[4225]: info: CoreStateMachine::syncState Jun 15 18:08:07 volumio volumio[4225]: info: CoreStateMachine::pushState Jun 15 18:08:07 volumio volumio[4225]: info: CoreStateMachine::getState Jun 15 18:08:07 volumio volumio[4225]: info: CoreCommandRouter::volumioPushState Jun 15 18:08:07 volumio volumio[4225]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 15 18:08:07 volumio volumio[4225]: info: interfaceApi::pushState Jun 15 18:08:07 volumio volumio[4225]: info: Pushing Favourites {"service":"spop","uri":"spotify:track:6gwUXJJkTEj1rXm5Fks0Jr","favourite":false} Jun 15 18:08:07 volumio volumio[994]: [Vollibrespot] : Event: SinkInactive Jun 15 18:08:07 volumio volumio[994]: [Vollibrespot] : Event: PlaybackStopped { track_id: SpotifyId { id: 273690301210807357512555782909957203329, audio_type: Track } } Jun 15 18:08:07 volumio volumio[4225]: [SpotifyConnect] Sink released Jun 15 18:08:07 volumio volumio[4225]: info: [1750010887809] ControllerSpotify::pushState Jun 15 18:08:07 volumio volumio[4225]: info: CoreCommandRouter::servicePushState Jun 15 18:08:07 volumio volumio[4225]: info: CoreStateMachine::syncState Jun 15 18:08:07 volumio volumio[4225]: info: CorePlayQueue::getTrack 22 Jun 15 18:08:07 volumio volumio[4225]: info: STATE SERVICE {"status":"stop","service":"spop","title":"Virtue","artist":"Jesse Cook","album":"Free Fall","albumart":"https://i.scdn.co/image/ab67616d0000b273d12120f6d2a0d48cd7c40e17","uri":"spotify:track:6gwUXJJkTEj1rXm5Fks0Jr","trackType":"spotify","seek":0,"duration":247,"samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","channels":2,"stream":false} Jun 15 18:08:07 volumio volumio[4225]: info: CURRENT POSITION 22 Jun 15 18:08:07 volumio volumio[4225]: info: CoreStateMachine::syncState stateService stop Jun 15 18:08:07 volumio volumio[4225]: info: CoreStateMachine::syncState currentStatus play Jun 15 18:08:07 volumio volumio[4225]: info: CURRENT POSITION 22 Jun 15 18:08:07 volumio volumio[4225]: info: CURRENT POSITION 23 Jun 15 18:08:07 volumio volumio[4225]: info: CoreStateMachine::play index undefined Jun 15 18:08:07 volumio volumio[4225]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 15 18:08:07 volumio volumio[4225]: info: CoreStateMachine::pushState Jun 15 18:08:07 volumio volumio[4225]: info: CoreStateMachine::getState Jun 15 18:08:07 volumio volumio[4225]: info: CoreCommandRouter::volumioPushState Jun 15 18:08:07 volumio volumio[4225]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 15 18:08:07 volumio volumio[4225]: info: interfaceApi::pushState Jun 15 18:08:07 volumio volumio[4225]: info: CorePlayQueue::getTrack 23 Jun 15 18:08:07 volumio volumio[4225]: info: CoreStateMachine::startPlaybackTimer Jun 15 18:08:07 volumio volumio[4225]: info: CorePlayQueue::getTrack 23 Jun 15 18:08:07 volumio volumio[4225]: info: [1750010887834] ControllerSpotify::clearAddPlayTrack Jun 15 18:08:07 volumio volumio[4225]: info: Setting this device active Jun 15 18:08:07 volumio volumio[4225]: info: CoreStateMachine::pushState Jun 15 18:08:07 volumio volumio[4225]: info: CoreStateMachine::getState Jun 15 18:08:07 volumio volumio[4225]: info: CoreCommandRouter::volumioPushState Jun 15 18:08:07 volumio volumio[4225]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 15 18:08:07 volumio volumio[4225]: info: interfaceApi::pushState Jun 15 18:08:07 volumio volumio[4225]: [SpotifyConnect] Device palyback is inactive Jun 15 18:08:07 volumio volumio[4225]: info: Pushing Favourites {"service":"spop","uri":"spotify:track:6gwUXJJkTEj1rXm5Fks0Jr","favourite":false} Jun 15 18:08:07 volumio volumio[4225]: info: Pushing Favourites {"service":"spop","uri":"spotify:track:6gwUXJJkTEj1rXm5Fks0Jr","favourite":false} Jun 15 18:08:08 volumio volumio[994]: [Vollibrespot] : Fetching autoplay context uri Jun 15 18:08:08 volumio volumio[994]: [Vollibrespot] : Event: TrackChanged { old_track_id: SpotifyId { id: 273690301210807357512555782909957203329, audio_type: Track }, track_id: SpotifyId { id: 273690301210807357512555782909957203329, audio_type: Track } } Jun 15 18:08:08 volumio volumio[994]: [Vollibrespot] : error 400 for uri hm://autoplay-enabled/query?uri= Jun 15 18:08:08 volumio volumio[994]: [Vollibrespot] : AutoplayError: MercuryError Jun 15 18:08:08 volumio volumio[994]: [Vollibrespot] : Event: PlaybackStopped { track_id: SpotifyId { id: 273690301210807357512555782909957203329, audio_type: Track } } Jun 15 18:08:08 volumio volumio[4225]: [SpotifyConnect] Virtue Jun 15 18:08:08 volumio volumio[4225]: info: [1750010888356] ControllerSpotify::pushState Jun 15 18:08:08 volumio volumio[4225]: info: CoreCommandRouter::servicePushState Jun 15 18:08:08 volumio volumio[4225]: info: CoreStateMachine::syncState Jun 15 18:08:08 volumio volumio[4225]: info: CorePlayQueue::getTrack 23 Jun 15 18:08:08 volumio volumio[4225]: info: STATE SERVICE {"status":"stop","service":"spop","title":"Virtue","artist":"Jesse Cook","album":"Free Fall","albumart":"https://i.scdn.co/image/ab67616d0000b273d12120f6d2a0d48cd7c40e17","uri":"spotify:track:6gwUXJJkTEj1rXm5Fks0Jr","trackType":"spotify","seek":0,"duration":247,"samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","channels":2,"stream":false} Jun 15 18:08:08 volumio volumio[4225]: info: CURRENT POSITION 23 Jun 15 18:08:08 volumio volumio[4225]: info: CoreStateMachine::syncState stateService stop Jun 15 18:08:08 volumio volumio[4225]: info: CoreStateMachine::syncState currentStatus stop Jun 15 18:08:08 volumio volumio[4225]: info: CoreStateMachine::pushState Jun 15 18:08:08 volumio volumio[4225]: info: CoreStateMachine::getState Jun 15 18:08:08 volumio volumio[4225]: info: CoreCommandRouter::volumioPushState Jun 15 18:08:08 volumio volumio[4225]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 15 18:08:08 volumio volumio[4225]: info: interfaceApi::pushState Jun 15 18:08:08 volumio volumio[4225]: info: No code Jun 15 18:08:08 volumio volumio[4225]: info: CoreStateMachine::pushState Jun 15 18:08:08 volumio volumio[4225]: info: CoreStateMachine::getState Jun 15 18:08:08 volumio volumio[4225]: info: CoreCommandRouter::volumioPushState Jun 15 18:08:08 volumio volumio[4225]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 15 18:08:08 volumio volumio[4225]: info: interfaceApi::pushState Jun 15 18:08:08 volumio volumio[4225]: [SpotifyConnect] Device palyback is inactive Jun 15 18:08:08 volumio volumio[4225]: info: Pushing Favourites {"service":"spop","uri":"spotify:track:6gwUXJJkTEj1rXm5Fks0Jr","favourite":false} Jun 15 18:08:08 volumio volumio[4225]: info: Pushing Favourites {"service":"spop","uri":"spotify:track:6gwUXJJkTEj1rXm5Fks0Jr","favourite":false} Jun 15 18:08:08 volumio volumio[994]: [Vollibrespot] : Fetching autoplay context uri Jun 15 18:08:08 volumio volumio[994]: [Vollibrespot] : Event: TrackChanged { old_track_id: SpotifyId { id: 273690301210807357512555782909957203329, audio_type: Track }, track_id: SpotifyId { id: 220500230687828957601305210623748416865, audio_type: Track } } Jun 15 18:08:08 volumio volumio[994]: [Vollibrespot] : error 400 for uri hm://autoplay-enabled/query?uri= Jun 15 18:08:08 volumio volumio[994]: [Vollibrespot] : AutoplayError: MercuryError Jun 15 18:08:08 volumio volumio[994]: [Vollibrespot] : Loading with Spotify URI Jun 15 18:08:08 volumio volumio[994]: [Vollibrespot] : (221611 ms) loaded Jun 15 18:08:08 volumio volumio[994]: [Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 220500230687828957601305210623748416865, audio_type: Track } } Jun 15 18:08:08 volumio volumio[994]: [Vollibrespot] : Event: SinkActive Jun 15 18:08:08 volumio volumio[4225]: [SpotifyConnect] Breeze From Saintes Maries - Live Jun 15 18:08:08 volumio volumio[4225]: [SpotifyConnect] Sink acquired Jun 15 18:08:08 volumio volumio[4225]: info: Continuing Spotify Session Jun 15 18:08:08 volumio volumio[4225]: info: Checking Spotify Web API Jun 15 18:08:09 volumio volumio[4225]: info: Is Not Connect Playback Jun 15 18:08:09 volumio volumio[4225]: info: [1750010889578] ControllerSpotify::pushState Jun 15 18:08:09 volumio volumio[4225]: info: CoreCommandRouter::servicePushState Jun 15 18:08:09 volumio volumio[4225]: info: CoreStateMachine::syncState Jun 15 18:08:09 volumio volumio[4225]: info: CoreStateMachine::pushState Jun 15 18:08:09 volumio volumio[4225]: info: CoreStateMachine::getState Jun 15 18:08:09 volumio volumio[4225]: info: CoreCommandRouter::volumioPushState Jun 15 18:08:09 volumio volumio[4225]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 15 18:08:09 volumio volumio[4225]: info: interfaceApi::pushState Jun 15 18:08:09 volumio volumio[4225]: info: Pushing Favourites {"service":"spop","uri":"spotify:track:531nFhmDKbyNE3kQLcWMvf","favourite":false} Jun 15 18:08:13 volumio volumio[4225]: info: VolumeController::SetAlsaVolume70 Jun 15 18:08:13 volumio volumio[4225]: info: Jun 15 18:08:13 volumio volumio[4225]: ---------------------------- MPD announces state update: mixer Jun 15 18:08:13 volumio volumio[4225]: info: ControllerMpd::getState Jun 15 18:08:13 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand status Jun 15 18:08:13 volumio volumio[4225]: info: sending command... Jun 15 18:08:13 volumio volumio[4225]: info: parsing response... Jun 15 18:08:13 volumio volumio[4225]: info: ControllerMpd::parseState Jun 15 18:08:13 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand playlistinfo Jun 15 18:08:13 volumio volumio[4225]: info: sending command... Jun 15 18:08:13 volumio volumio[4225]: null Jun 15 18:08:13 volumio volumio[4225]: info: VolumeController::Volume 70 Jun 15 18:08:13 volumio volumio[4225]: info: CoreStateMachine::pushState Jun 15 18:08:13 volumio volumio[4225]: info: CoreStateMachine::getState Jun 15 18:08:13 volumio volumio[4225]: info: CoreCommandRouter::volumioPushState Jun 15 18:08:13 volumio volumio[4225]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 15 18:08:13 volumio volumio[4225]: info: interfaceApi::pushState Jun 15 18:08:13 volumio volumio[4225]: info: parsing response... Jun 15 18:08:13 volumio volumio[4225]: info: ControllerMpd::parseTrackInfo Jun 15 18:08:13 volumio volumio[4225]: info: ControllerMpd::pushState Jun 15 18:08:13 volumio volumio[4225]: info: CoreCommandRouter::servicePushState Jun 15 18:08:13 volumio volumio[4225]: info: CoreStateMachine::syncState Jun 15 18:08:13 volumio volumio[4225]: info: CorePlayQueue::getTrack 23 Jun 15 18:08:13 volumio volumio[4225]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Jun 15 18:08:13 volumio volumio[4225]: info: ------------------------------ 60ms Jun 15 18:08:13 volumio volumio[4225]: info: Pushing Favourites {"service":"spop","uri":"spotify:track:531nFhmDKbyNE3kQLcWMvf","favourite":false} Jun 15 18:08:13 volumio volumio[994]: [Vollibrespot] : Event: Volume { volume_to_mixer: 45875 } Jun 15 18:08:13 volumio volumio[4225]: info: Jun 15 18:08:13 volumio volumio[4225]: ---------------------------- MPD announces state update: mixer Jun 15 18:08:13 volumio volumio[4225]: info: ControllerMpd::getState Jun 15 18:08:13 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand status Jun 15 18:08:13 volumio volumio[4225]: info: sending command... Jun 15 18:08:13 volumio volumio[4225]: [SpotifyConnect] Volume Spotify: 70.00076295109483 Volumio: 70 Jun 15 18:08:13 volumio volumio[4225]: info: parsing response... Jun 15 18:08:13 volumio volumio[4225]: info: ControllerMpd::parseState Jun 15 18:08:13 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand playlistinfo Jun 15 18:08:13 volumio volumio[4225]: info: sending command... Jun 15 18:08:13 volumio volumio[4225]: info: parsing response... Jun 15 18:08:13 volumio volumio[4225]: info: ControllerMpd::parseTrackInfo Jun 15 18:08:13 volumio volumio[4225]: info: ControllerMpd::pushState Jun 15 18:08:13 volumio volumio[4225]: info: CoreCommandRouter::servicePushState Jun 15 18:08:13 volumio volumio[4225]: info: CoreStateMachine::syncState Jun 15 18:08:13 volumio volumio[4225]: info: CorePlayQueue::getTrack 23 Jun 15 18:08:13 volumio volumio[4225]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Jun 15 18:08:13 volumio volumio[4225]: info: ------------------------------ 13ms Jun 15 18:08:14 volumio volumio[4225]: info: VolumeController::SetAlsaVolume65 Jun 15 18:08:14 volumio volumio[4225]: info: Jun 15 18:08:14 volumio volumio[4225]: ---------------------------- MPD announces state update: mixer Jun 15 18:08:14 volumio volumio[4225]: info: ControllerMpd::getState Jun 15 18:08:14 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand status Jun 15 18:08:14 volumio volumio[4225]: info: sending command... Jun 15 18:08:14 volumio volumio[4225]: null Jun 15 18:08:14 volumio volumio[4225]: info: VolumeController::Volume 65 Jun 15 18:08:14 volumio volumio[4225]: info: CoreStateMachine::pushState Jun 15 18:08:14 volumio volumio[4225]: info: CoreStateMachine::getState Jun 15 18:08:14 volumio volumio[4225]: info: CoreCommandRouter::volumioPushState Jun 15 18:08:14 volumio volumio[4225]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 15 18:08:14 volumio volumio[4225]: info: interfaceApi::pushState Jun 15 18:08:14 volumio volumio[4225]: info: Pushing Favourites {"service":"spop","uri":"spotify:track:531nFhmDKbyNE3kQLcWMvf","favourite":false} Jun 15 18:08:14 volumio volumio[4225]: info: parsing response... Jun 15 18:08:14 volumio volumio[4225]: info: ControllerMpd::parseState Jun 15 18:08:14 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand playlistinfo Jun 15 18:08:14 volumio volumio[4225]: info: sending command... Jun 15 18:08:14 volumio volumio[4225]: info: parsing response... Jun 15 18:08:14 volumio volumio[4225]: info: ControllerMpd::parseTrackInfo Jun 15 18:08:14 volumio volumio[4225]: info: ControllerMpd::pushState Jun 15 18:08:14 volumio volumio[4225]: info: CoreCommandRouter::servicePushState Jun 15 18:08:14 volumio volumio[4225]: info: CoreStateMachine::syncState Jun 15 18:08:14 volumio volumio[4225]: info: CorePlayQueue::getTrack 23 Jun 15 18:08:14 volumio volumio[4225]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Jun 15 18:08:14 volumio volumio[4225]: info: ------------------------------ 56ms Jun 15 18:08:14 volumio volumio[994]: [Vollibrespot] : Event: Volume { volume_to_mixer: 42598 } Jun 15 18:08:14 volumio volumio[4225]: [SpotifyConnect] Volume Spotify: 65.00038147554741 Volumio: 65 Jun 15 18:08:14 volumio volumio[4225]: info: VolumeController::SetAlsaVolume62 Jun 15 18:08:14 volumio volumio[4225]: info: Jun 15 18:08:14 volumio volumio[4225]: ---------------------------- MPD announces state update: mixer Jun 15 18:08:14 volumio volumio[4225]: info: ControllerMpd::getState Jun 15 18:08:14 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand status Jun 15 18:08:14 volumio volumio[4225]: info: sending command... Jun 15 18:08:14 volumio volumio[4225]: info: parsing response... Jun 15 18:08:14 volumio volumio[4225]: info: ControllerMpd::parseState Jun 15 18:08:14 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand playlistinfo Jun 15 18:08:14 volumio volumio[4225]: info: sending command... Jun 15 18:08:14 volumio volumio[4225]: null Jun 15 18:08:14 volumio volumio[4225]: info: VolumeController::Volume 62 Jun 15 18:08:14 volumio volumio[4225]: info: CoreStateMachine::pushState Jun 15 18:08:14 volumio volumio[4225]: info: CoreStateMachine::getState Jun 15 18:08:14 volumio volumio[4225]: info: CoreCommandRouter::volumioPushState Jun 15 18:08:14 volumio volumio[4225]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 15 18:08:14 volumio volumio[4225]: info: interfaceApi::pushState Jun 15 18:08:14 volumio volumio[4225]: info: parsing response... Jun 15 18:08:14 volumio volumio[4225]: info: ControllerMpd::parseTrackInfo Jun 15 18:08:14 volumio volumio[4225]: info: ControllerMpd::pushState Jun 15 18:08:14 volumio volumio[4225]: info: CoreCommandRouter::servicePushState Jun 15 18:08:14 volumio volumio[4225]: info: CoreStateMachine::syncState Jun 15 18:08:14 volumio volumio[4225]: info: CorePlayQueue::getTrack 23 Jun 15 18:08:14 volumio volumio[4225]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Jun 15 18:08:14 volumio volumio[4225]: info: ------------------------------ 40ms Jun 15 18:08:14 volumio volumio[4225]: info: Pushing Favourites {"service":"spop","uri":"spotify:track:531nFhmDKbyNE3kQLcWMvf","favourite":false} Jun 15 18:08:14 volumio volumio[4225]: info: VolumeController::SetAlsaVolume63 Jun 15 18:08:14 volumio volumio[4225]: info: Jun 15 18:08:14 volumio volumio[4225]: ---------------------------- MPD announces state update: mixer Jun 15 18:08:14 volumio volumio[4225]: info: ControllerMpd::getState Jun 15 18:08:14 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand status Jun 15 18:08:14 volumio volumio[4225]: info: sending command... Jun 15 18:08:14 volumio volumio[4225]: null Jun 15 18:08:14 volumio volumio[4225]: info: VolumeController::Volume 63 Jun 15 18:08:14 volumio volumio[4225]: info: CoreStateMachine::pushState Jun 15 18:08:14 volumio volumio[4225]: info: CoreStateMachine::getState Jun 15 18:08:14 volumio volumio[4225]: info: CoreCommandRouter::volumioPushState Jun 15 18:08:14 volumio volumio[4225]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 15 18:08:14 volumio volumio[4225]: info: interfaceApi::pushState Jun 15 18:08:14 volumio volumio[4225]: info: parsing response... Jun 15 18:08:14 volumio volumio[4225]: info: ControllerMpd::parseState Jun 15 18:08:14 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand playlistinfo Jun 15 18:08:14 volumio volumio[4225]: info: sending command... Jun 15 18:08:14 volumio volumio[4225]: info: Pushing Favourites {"service":"spop","uri":"spotify:track:531nFhmDKbyNE3kQLcWMvf","favourite":false} Jun 15 18:08:14 volumio volumio[4225]: info: parsing response... Jun 15 18:08:14 volumio volumio[4225]: info: ControllerMpd::parseTrackInfo Jun 15 18:08:14 volumio volumio[4225]: info: ControllerMpd::pushState Jun 15 18:08:14 volumio volumio[4225]: info: CoreCommandRouter::servicePushState Jun 15 18:08:14 volumio volumio[4225]: info: CoreStateMachine::syncState Jun 15 18:08:14 volumio volumio[4225]: info: CorePlayQueue::getTrack 23 Jun 15 18:08:14 volumio volumio[4225]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Jun 15 18:08:14 volumio volumio[4225]: info: ------------------------------ 51ms Jun 15 18:08:15 volumio volumio[994]: [Vollibrespot] : Event: Volume { volume_to_mixer: 40632 } Jun 15 18:08:15 volumio volumio[4225]: info: Jun 15 18:08:15 volumio volumio[4225]: ---------------------------- MPD announces state update: mixer Jun 15 18:08:15 volumio volumio[4225]: info: ControllerMpd::getState Jun 15 18:08:15 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand status Jun 15 18:08:15 volumio volumio[4225]: info: sending command... Jun 15 18:08:15 volumio volumio[4225]: [SpotifyConnect] Volume Spotify: 62.0004577706569 Volumio: 62 Jun 15 18:08:15 volumio volumio[4225]: info: parsing response... Jun 15 18:08:15 volumio volumio[4225]: info: ControllerMpd::parseState Jun 15 18:08:15 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand playlistinfo Jun 15 18:08:15 volumio volumio[4225]: info: sending command... Jun 15 18:08:15 volumio volumio[4225]: info: parsing response... Jun 15 18:08:15 volumio volumio[4225]: info: ControllerMpd::parseTrackInfo Jun 15 18:08:15 volumio volumio[4225]: info: ControllerMpd::pushState Jun 15 18:08:15 volumio volumio[4225]: info: CoreCommandRouter::servicePushState Jun 15 18:08:15 volumio volumio[4225]: info: CoreStateMachine::syncState Jun 15 18:08:15 volumio volumio[4225]: info: CorePlayQueue::getTrack 23 Jun 15 18:08:15 volumio volumio[4225]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Jun 15 18:08:15 volumio volumio[4225]: info: ------------------------------ 10ms Jun 15 18:08:15 volumio volumio[994]: [Vollibrespot] : Event: Volume { volume_to_mixer: 41288 } Jun 15 18:08:15 volumio volumio[4225]: info: Jun 15 18:08:15 volumio volumio[4225]: ---------------------------- MPD announces state update: mixer Jun 15 18:08:15 volumio volumio[4225]: info: ControllerMpd::getState Jun 15 18:08:15 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand status Jun 15 18:08:15 volumio volumio[4225]: info: sending command... Jun 15 18:08:15 volumio volumio[4225]: [SpotifyConnect] Volume Spotify: 63.00144960708018 Volumio: 63 Jun 15 18:08:15 volumio volumio[4225]: info: parsing response... Jun 15 18:08:15 volumio volumio[4225]: info: ControllerMpd::parseState Jun 15 18:08:15 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand playlistinfo Jun 15 18:08:15 volumio volumio[4225]: info: sending command... Jun 15 18:08:15 volumio volumio[4225]: info: parsing response... Jun 15 18:08:15 volumio volumio[4225]: info: ControllerMpd::parseTrackInfo Jun 15 18:08:15 volumio volumio[4225]: info: ControllerMpd::pushState Jun 15 18:08:15 volumio volumio[4225]: info: CoreCommandRouter::servicePushState Jun 15 18:08:15 volumio volumio[4225]: info: CoreStateMachine::syncState Jun 15 18:08:15 volumio volumio[4225]: info: CorePlayQueue::getTrack 23 Jun 15 18:08:15 volumio volumio[4225]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Jun 15 18:08:15 volumio volumio[4225]: info: ------------------------------ 12ms Jun 15 18:08:15 volumio volumio[4225]: info: VolumeController::SetAlsaVolume62 Jun 15 18:08:15 volumio volumio[4225]: info: Jun 15 18:08:15 volumio volumio[4225]: ---------------------------- MPD announces state update: mixer Jun 15 18:08:15 volumio volumio[4225]: info: ControllerMpd::getState Jun 15 18:08:15 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand status Jun 15 18:08:15 volumio volumio[4225]: info: sending command... Jun 15 18:08:15 volumio volumio[4225]: info: parsing response... Jun 15 18:08:15 volumio volumio[4225]: info: ControllerMpd::parseState Jun 15 18:08:15 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand playlistinfo Jun 15 18:08:15 volumio volumio[4225]: info: sending command... Jun 15 18:08:15 volumio volumio[4225]: null Jun 15 18:08:15 volumio volumio[4225]: info: VolumeController::Volume 62 Jun 15 18:08:15 volumio volumio[4225]: info: CoreStateMachine::pushState Jun 15 18:08:15 volumio volumio[4225]: info: CoreStateMachine::getState Jun 15 18:08:15 volumio volumio[4225]: info: CoreCommandRouter::volumioPushState Jun 15 18:08:15 volumio volumio[4225]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 15 18:08:15 volumio volumio[4225]: info: interfaceApi::pushState Jun 15 18:08:15 volumio volumio[4225]: info: parsing response... Jun 15 18:08:15 volumio volumio[4225]: info: ControllerMpd::parseTrackInfo Jun 15 18:08:15 volumio volumio[4225]: info: ControllerMpd::pushState Jun 15 18:08:15 volumio volumio[4225]: info: CoreCommandRouter::servicePushState Jun 15 18:08:15 volumio volumio[4225]: info: CoreStateMachine::syncState Jun 15 18:08:15 volumio volumio[4225]: info: CorePlayQueue::getTrack 23 Jun 15 18:08:15 volumio volumio[4225]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Jun 15 18:08:15 volumio volumio[4225]: info: ------------------------------ 42ms Jun 15 18:08:15 volumio volumio[4225]: info: Pushing Favourites {"service":"spop","uri":"spotify:track:531nFhmDKbyNE3kQLcWMvf","favourite":false} Jun 15 18:08:15 volumio volumio[994]: [Vollibrespot] : Event: Volume { volume_to_mixer: 40632 } Jun 15 18:08:15 volumio volumio[4225]: [SpotifyConnect] Volume Spotify: 62.0004577706569 Volumio: 62 Jun 15 18:08:49 volumio volumio[4225]: info: CoreCommandRouter::volumioPause Jun 15 18:08:49 volumio volumio[4225]: info: CoreStateMachine::pause Jun 15 18:08:49 volumio volumio[4225]: info: CoreStateMachine::stPlaybackTimer Jun 15 18:08:49 volumio volumio[4225]: info: CoreStateMachine::servicePause Jun 15 18:08:49 volumio volumio[4225]: info: CoreCommandRouter::servicePause Jun 15 18:08:49 volumio volumio[4225]: error: WARNING: No pause method for service undefined Jun 15 18:08:53 volumio volumio[4225]: info: CoreCommandRouter::volumioPause Jun 15 18:08:53 volumio volumio[4225]: info: CoreStateMachine::pause Jun 15 18:09:00 volumio volumio[4225]: info: CoreCommandRouter::volumioPause Jun 15 18:09:00 volumio volumio[4225]: info: CoreStateMachine::pause Jun 15 18:09:04 volumio volumio[4225]: info: VolumeController::SetAlsaVolume65 Jun 15 18:09:04 volumio volumio[4225]: info: Jun 15 18:09:04 volumio volumio[4225]: ---------------------------- MPD announces state update: mixer Jun 15 18:09:04 volumio volumio[4225]: info: ControllerMpd::getState Jun 15 18:09:04 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand status Jun 15 18:09:04 volumio volumio[4225]: info: sending command... Jun 15 18:09:04 volumio volumio[4225]: info: parsing response... Jun 15 18:09:04 volumio volumio[4225]: info: ControllerMpd::parseState Jun 15 18:09:04 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand playlistinfo Jun 15 18:09:04 volumio volumio[4225]: info: sending command... Jun 15 18:09:04 volumio volumio[4225]: null Jun 15 18:09:04 volumio volumio[4225]: info: VolumeController::Volume 65 Jun 15 18:09:04 volumio volumio[4225]: info: CoreStateMachine::pushState Jun 15 18:09:04 volumio volumio[4225]: info: CoreStateMachine::getState Jun 15 18:09:04 volumio volumio[4225]: info: CoreCommandRouter::volumioPushState Jun 15 18:09:04 volumio volumio[4225]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 15 18:09:04 volumio volumio[4225]: info: interfaceApi::pushState Jun 15 18:09:04 volumio volumio[4225]: info: parsing response... Jun 15 18:09:04 volumio volumio[4225]: info: ControllerMpd::parseTrackInfo Jun 15 18:09:04 volumio volumio[4225]: info: ControllerMpd::pushState Jun 15 18:09:04 volumio volumio[4225]: info: CoreCommandRouter::servicePushState Jun 15 18:09:04 volumio volumio[4225]: info: CoreStateMachine::syncState Jun 15 18:09:04 volumio volumio[4225]: info: CorePlayQueue::getTrack 23 Jun 15 18:09:04 volumio volumio[4225]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Jun 15 18:09:04 volumio volumio[4225]: info: ------------------------------ 32ms Jun 15 18:09:04 volumio volumio[4225]: info: Pushing Favourites {"service":"spop","uri":"spotify:track:531nFhmDKbyNE3kQLcWMvf","favourite":false} Jun 15 18:09:04 volumio volumio[994]: [Vollibrespot] : Event: Volume { volume_to_mixer: 42598 } Jun 15 18:09:04 volumio volumio[4225]: [SpotifyConnect] Volume Spotify: 65.00038147554741 Volumio: 65 Jun 15 18:09:05 volumio volumio[4225]: info: VolumeController::SetAlsaVolume67 Jun 15 18:09:05 volumio volumio[4225]: info: Jun 15 18:09:05 volumio volumio[4225]: ---------------------------- MPD announces state update: mixer Jun 15 18:09:05 volumio volumio[4225]: info: ControllerMpd::getState Jun 15 18:09:05 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand status Jun 15 18:09:05 volumio volumio[4225]: info: sending command... Jun 15 18:09:05 volumio volumio[4225]: info: parsing response... Jun 15 18:09:05 volumio volumio[4225]: info: ControllerMpd::parseState Jun 15 18:09:05 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand playlistinfo Jun 15 18:09:05 volumio volumio[4225]: info: sending command... Jun 15 18:09:05 volumio volumio[4225]: null Jun 15 18:09:05 volumio volumio[4225]: info: VolumeController::Volume 67 Jun 15 18:09:05 volumio volumio[4225]: info: CoreStateMachine::pushState Jun 15 18:09:05 volumio volumio[4225]: info: CoreStateMachine::getState Jun 15 18:09:05 volumio volumio[4225]: info: CoreCommandRouter::volumioPushState Jun 15 18:09:05 volumio volumio[4225]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 15 18:09:05 volumio volumio[4225]: info: interfaceApi::pushState Jun 15 18:09:05 volumio volumio[4225]: info: parsing response... Jun 15 18:09:05 volumio volumio[4225]: info: ControllerMpd::parseTrackInfo Jun 15 18:09:05 volumio volumio[4225]: info: ControllerMpd::pushState Jun 15 18:09:05 volumio volumio[4225]: info: CoreCommandRouter::servicePushState Jun 15 18:09:05 volumio volumio[4225]: info: CoreStateMachine::syncState Jun 15 18:09:05 volumio volumio[4225]: info: CorePlayQueue::getTrack 23 Jun 15 18:09:05 volumio volumio[4225]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Jun 15 18:09:05 volumio volumio[4225]: info: ------------------------------ 33ms Jun 15 18:09:05 volumio volumio[4225]: info: Pushing Favourites {"service":"spop","uri":"spotify:track:531nFhmDKbyNE3kQLcWMvf","favourite":false} Jun 15 18:09:05 volumio volumio[4225]: info: VolumeController::SetAlsaVolume69 Jun 15 18:09:05 volumio volumio[4225]: info: Jun 15 18:09:05 volumio volumio[4225]: ---------------------------- MPD announces state update: mixer Jun 15 18:09:05 volumio volumio[4225]: info: ControllerMpd::getState Jun 15 18:09:05 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand status Jun 15 18:09:05 volumio volumio[4225]: info: sending command... Jun 15 18:09:05 volumio volumio[4225]: info: parsing response... Jun 15 18:09:05 volumio volumio[4225]: info: ControllerMpd::parseState Jun 15 18:09:05 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand playlistinfo Jun 15 18:09:05 volumio volumio[4225]: info: sending command... Jun 15 18:09:05 volumio volumio[4225]: null Jun 15 18:09:05 volumio volumio[4225]: info: VolumeController::Volume 69 Jun 15 18:09:05 volumio volumio[4225]: info: CoreStateMachine::pushState Jun 15 18:09:05 volumio volumio[4225]: info: CoreStateMachine::getState Jun 15 18:09:05 volumio volumio[4225]: info: CoreCommandRouter::volumioPushState Jun 15 18:09:05 volumio volumio[4225]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 15 18:09:05 volumio volumio[4225]: info: interfaceApi::pushState Jun 15 18:09:05 volumio volumio[4225]: info: parsing response... Jun 15 18:09:05 volumio volumio[4225]: info: ControllerMpd::parseTrackInfo Jun 15 18:09:05 volumio volumio[4225]: info: ControllerMpd::pushState Jun 15 18:09:05 volumio volumio[4225]: info: CoreCommandRouter::servicePushState Jun 15 18:09:05 volumio volumio[4225]: info: CoreStateMachine::syncState Jun 15 18:09:05 volumio volumio[4225]: info: CorePlayQueue::getTrack 23 Jun 15 18:09:05 volumio volumio[4225]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Jun 15 18:09:05 volumio volumio[4225]: info: ------------------------------ 37ms Jun 15 18:09:05 volumio volumio[4225]: info: Pushing Favourites {"service":"spop","uri":"spotify:track:531nFhmDKbyNE3kQLcWMvf","favourite":false} Jun 15 18:09:05 volumio volumio[994]: [Vollibrespot] : Event: Volume { volume_to_mixer: 43909 } Jun 15 18:09:05 volumio volumio[4225]: info: Jun 15 18:09:05 volumio volumio[4225]: ---------------------------- MPD announces state update: mixer Jun 15 18:09:05 volumio volumio[4225]: info: ControllerMpd::getState Jun 15 18:09:05 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand status Jun 15 18:09:05 volumio volumio[4225]: info: sending command... Jun 15 18:09:05 volumio volumio[4225]: info: parsing response... Jun 15 18:09:05 volumio volumio[4225]: info: ControllerMpd::parseState Jun 15 18:09:05 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand playlistinfo Jun 15 18:09:05 volumio volumio[4225]: info: sending command... Jun 15 18:09:05 volumio volumio[4225]: [SpotifyConnect] Volume Spotify: 67.00083924620431 Volumio: 67 Jun 15 18:09:05 volumio volumio[4225]: info: parsing response... Jun 15 18:09:05 volumio volumio[4225]: info: ControllerMpd::parseTrackInfo Jun 15 18:09:05 volumio volumio[4225]: info: ControllerMpd::pushState Jun 15 18:09:05 volumio volumio[4225]: info: CoreCommandRouter::servicePushState Jun 15 18:09:05 volumio volumio[4225]: info: CoreStateMachine::syncState Jun 15 18:09:05 volumio volumio[4225]: info: CorePlayQueue::getTrack 23 Jun 15 18:09:05 volumio volumio[4225]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Jun 15 18:09:05 volumio volumio[4225]: info: ------------------------------ 8ms Jun 15 18:09:05 volumio volumio[994]: [Vollibrespot] : Event: Volume { volume_to_mixer: 45220 } Jun 15 18:09:05 volumio volumio[4225]: info: Jun 15 18:09:05 volumio volumio[4225]: ---------------------------- MPD announces state update: mixer Jun 15 18:09:05 volumio volumio[4225]: info: ControllerMpd::getState Jun 15 18:09:05 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand status Jun 15 18:09:05 volumio volumio[4225]: info: sending command... Jun 15 18:09:05 volumio volumio[4225]: info: parsing response... Jun 15 18:09:05 volumio volumio[4225]: info: ControllerMpd::parseState Jun 15 18:09:05 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand playlistinfo Jun 15 18:09:05 volumio volumio[4225]: info: sending command... Jun 15 18:09:05 volumio volumio[4225]: [SpotifyConnect] Volume Spotify: 69.00129701686122 Volumio: 69 Jun 15 18:09:05 volumio volumio[4225]: info: parsing response... Jun 15 18:09:05 volumio volumio[4225]: info: ControllerMpd::parseTrackInfo Jun 15 18:09:05 volumio volumio[4225]: info: ControllerMpd::pushState Jun 15 18:09:05 volumio volumio[4225]: info: CoreCommandRouter::servicePushState Jun 15 18:09:05 volumio volumio[4225]: info: CoreStateMachine::syncState Jun 15 18:09:05 volumio volumio[4225]: info: CorePlayQueue::getTrack 23 Jun 15 18:09:05 volumio volumio[4225]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Jun 15 18:09:05 volumio volumio[4225]: info: ------------------------------ 9ms Jun 15 18:09:05 volumio volumio[4225]: info: VolumeController::SetAlsaVolume67 Jun 15 18:09:05 volumio volumio[4225]: info: Jun 15 18:09:05 volumio volumio[4225]: ---------------------------- MPD announces state update: mixer Jun 15 18:09:05 volumio volumio[4225]: info: ControllerMpd::getState Jun 15 18:09:05 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand status Jun 15 18:09:05 volumio volumio[4225]: info: sending command... Jun 15 18:09:05 volumio volumio[4225]: info: parsing response... Jun 15 18:09:05 volumio volumio[4225]: info: ControllerMpd::parseState Jun 15 18:09:05 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand playlistinfo Jun 15 18:09:05 volumio volumio[4225]: info: sending command... Jun 15 18:09:05 volumio volumio[4225]: null Jun 15 18:09:05 volumio volumio[4225]: info: VolumeController::Volume 67 Jun 15 18:09:05 volumio volumio[4225]: info: CoreStateMachine::pushState Jun 15 18:09:05 volumio volumio[4225]: info: CoreStateMachine::getState Jun 15 18:09:05 volumio volumio[4225]: info: CoreCommandRouter::volumioPushState Jun 15 18:09:06 volumio volumio[4225]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 15 18:09:06 volumio volumio[4225]: info: interfaceApi::pushState Jun 15 18:09:06 volumio volumio[4225]: info: parsing response... Jun 15 18:09:06 volumio volumio[4225]: info: ControllerMpd::parseTrackInfo Jun 15 18:09:06 volumio volumio[4225]: info: ControllerMpd::pushState Jun 15 18:09:06 volumio volumio[4225]: info: CoreCommandRouter::servicePushState Jun 15 18:09:06 volumio volumio[4225]: info: CoreStateMachine::syncState Jun 15 18:09:06 volumio volumio[4225]: info: CorePlayQueue::getTrack 23 Jun 15 18:09:06 volumio volumio[4225]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Jun 15 18:09:06 volumio volumio[4225]: info: ------------------------------ 32ms Jun 15 18:09:06 volumio volumio[4225]: info: Pushing Favourites {"service":"spop","uri":"spotify:track:531nFhmDKbyNE3kQLcWMvf","favourite":false} Jun 15 18:09:06 volumio volumio[994]: [Vollibrespot] : Event: Volume { volume_to_mixer: 43909 } Jun 15 18:09:06 volumio volumio[4225]: [SpotifyConnect] Volume Spotify: 67.00083924620431 Volumio: 67 Jun 15 18:09:07 volumio volumio[4225]: info: VolumeController::SetAlsaVolume61 Jun 15 18:09:07 volumio volumio[4225]: info: Jun 15 18:09:07 volumio volumio[4225]: ---------------------------- MPD announces state update: mixer Jun 15 18:09:07 volumio volumio[4225]: info: ControllerMpd::getState Jun 15 18:09:07 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand status Jun 15 18:09:07 volumio volumio[4225]: info: sending command... Jun 15 18:09:07 volumio volumio[4225]: info: parsing response... Jun 15 18:09:07 volumio volumio[4225]: info: ControllerMpd::parseState Jun 15 18:09:07 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand playlistinfo Jun 15 18:09:07 volumio volumio[4225]: info: sending command... Jun 15 18:09:07 volumio volumio[4225]: null Jun 15 18:09:07 volumio volumio[4225]: info: VolumeController::Volume 61 Jun 15 18:09:07 volumio volumio[4225]: info: CoreStateMachine::pushState Jun 15 18:09:07 volumio volumio[4225]: info: CoreStateMachine::getState Jun 15 18:09:07 volumio volumio[4225]: info: CoreCommandRouter::volumioPushState Jun 15 18:09:07 volumio volumio[4225]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 15 18:09:07 volumio volumio[4225]: info: interfaceApi::pushState Jun 15 18:09:07 volumio volumio[4225]: info: parsing response... Jun 15 18:09:07 volumio volumio[4225]: info: ControllerMpd::parseTrackInfo Jun 15 18:09:07 volumio volumio[4225]: info: ControllerMpd::pushState Jun 15 18:09:07 volumio volumio[4225]: info: CoreCommandRouter::servicePushState Jun 15 18:09:07 volumio volumio[4225]: info: CoreStateMachine::syncState Jun 15 18:09:07 volumio volumio[4225]: info: CorePlayQueue::getTrack 23 Jun 15 18:09:07 volumio volumio[4225]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Jun 15 18:09:07 volumio volumio[4225]: info: ------------------------------ 37ms Jun 15 18:09:07 volumio volumio[4225]: info: Pushing Favourites {"service":"spop","uri":"spotify:track:531nFhmDKbyNE3kQLcWMvf","favourite":false} Jun 15 18:09:07 volumio volumio[994]: [Vollibrespot] : Event: Volume { volume_to_mixer: 39977 } Jun 15 18:09:07 volumio volumio[4225]: [SpotifyConnect] Volume Spotify: 61.00099183642329 Volumio: 61 Jun 15 18:09:07 volumio volumio[4225]: info: VolumeController::SetAlsaVolume58 Jun 15 18:09:07 volumio volumio[4225]: info: Jun 15 18:09:07 volumio volumio[4225]: ---------------------------- MPD announces state update: mixer Jun 15 18:09:07 volumio volumio[4225]: info: ControllerMpd::getState Jun 15 18:09:07 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand status Jun 15 18:09:07 volumio volumio[4225]: info: sending command... Jun 15 18:09:07 volumio volumio[4225]: null Jun 15 18:09:07 volumio volumio[4225]: info: VolumeController::Volume 58 Jun 15 18:09:07 volumio volumio[4225]: info: CoreStateMachine::pushState Jun 15 18:09:07 volumio volumio[4225]: info: CoreStateMachine::getState Jun 15 18:09:07 volumio volumio[4225]: info: CoreCommandRouter::volumioPushState Jun 15 18:09:07 volumio volumio[4225]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 15 18:09:07 volumio volumio[4225]: info: interfaceApi::pushState Jun 15 18:09:07 volumio volumio[4225]: info: parsing response... Jun 15 18:09:07 volumio volumio[4225]: info: ControllerMpd::parseState Jun 15 18:09:07 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand playlistinfo Jun 15 18:09:07 volumio volumio[4225]: info: sending command... Jun 15 18:09:07 volumio volumio[4225]: info: Pushing Favourites {"service":"spop","uri":"spotify:track:531nFhmDKbyNE3kQLcWMvf","favourite":false} Jun 15 18:09:07 volumio volumio[4225]: info: parsing response... Jun 15 18:09:07 volumio volumio[4225]: info: ControllerMpd::parseTrackInfo Jun 15 18:09:07 volumio volumio[4225]: info: ControllerMpd::pushState Jun 15 18:09:07 volumio volumio[4225]: info: CoreCommandRouter::servicePushState Jun 15 18:09:07 volumio volumio[4225]: info: CoreStateMachine::syncState Jun 15 18:09:07 volumio volumio[4225]: info: CorePlayQueue::getTrack 23 Jun 15 18:09:07 volumio volumio[4225]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Jun 15 18:09:07 volumio volumio[4225]: info: ------------------------------ 41ms Jun 15 18:09:07 volumio volumio[4225]: info: VolumeController::SetAlsaVolume59 Jun 15 18:09:07 volumio volumio[4225]: info: Jun 15 18:09:07 volumio volumio[4225]: ---------------------------- MPD announces state update: mixer Jun 15 18:09:07 volumio volumio[4225]: info: ControllerMpd::getState Jun 15 18:09:07 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand status Jun 15 18:09:07 volumio volumio[4225]: info: sending command... Jun 15 18:09:07 volumio volumio[4225]: info: parsing response... Jun 15 18:09:07 volumio volumio[4225]: info: ControllerMpd::parseState Jun 15 18:09:07 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand playlistinfo Jun 15 18:09:07 volumio volumio[4225]: info: sending command... Jun 15 18:09:07 volumio volumio[4225]: null Jun 15 18:09:07 volumio volumio[4225]: info: VolumeController::Volume 59 Jun 15 18:09:07 volumio volumio[4225]: info: CoreStateMachine::pushState Jun 15 18:09:07 volumio volumio[4225]: info: CoreStateMachine::getState Jun 15 18:09:07 volumio volumio[4225]: info: CoreCommandRouter::volumioPushState Jun 15 18:09:07 volumio volumio[4225]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 15 18:09:07 volumio volumio[4225]: info: interfaceApi::pushState Jun 15 18:09:07 volumio volumio[4225]: info: parsing response... Jun 15 18:09:07 volumio volumio[4225]: info: ControllerMpd::parseTrackInfo Jun 15 18:09:07 volumio volumio[4225]: info: ControllerMpd::pushState Jun 15 18:09:07 volumio volumio[4225]: info: CoreCommandRouter::servicePushState Jun 15 18:09:07 volumio volumio[4225]: info: CoreStateMachine::syncState Jun 15 18:09:07 volumio volumio[4225]: info: CorePlayQueue::getTrack 23 Jun 15 18:09:07 volumio volumio[4225]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Jun 15 18:09:07 volumio volumio[4225]: info: ------------------------------ 30ms Jun 15 18:09:07 volumio volumio[4225]: info: Pushing Favourites {"service":"spop","uri":"spotify:track:531nFhmDKbyNE3kQLcWMvf","favourite":false} Jun 15 18:09:07 volumio volumio[994]: [Vollibrespot] : Event: Volume { volume_to_mixer: 38011 } Jun 15 18:09:07 volumio volumio[4225]: info: Jun 15 18:09:07 volumio volumio[4225]: ---------------------------- MPD announces state update: mixer Jun 15 18:09:07 volumio volumio[4225]: info: ControllerMpd::getState Jun 15 18:09:07 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand status Jun 15 18:09:07 volumio volumio[4225]: info: sending command... Jun 15 18:09:07 volumio volumio[4225]: [SpotifyConnect] Volume Spotify: 58.001068131532776 Volumio: 58 Jun 15 18:09:07 volumio volumio[4225]: info: parsing response... Jun 15 18:09:07 volumio volumio[4225]: info: ControllerMpd::parseState Jun 15 18:09:07 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand playlistinfo Jun 15 18:09:07 volumio volumio[4225]: info: sending command... Jun 15 18:09:07 volumio volumio[4225]: info: parsing response... Jun 15 18:09:07 volumio volumio[4225]: info: ControllerMpd::parseTrackInfo Jun 15 18:09:07 volumio volumio[4225]: info: ControllerMpd::pushState Jun 15 18:09:07 volumio volumio[4225]: info: CoreCommandRouter::servicePushState Jun 15 18:09:07 volumio volumio[4225]: info: CoreStateMachine::syncState Jun 15 18:09:07 volumio volumio[4225]: info: CorePlayQueue::getTrack 23 Jun 15 18:09:07 volumio volumio[4225]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Jun 15 18:09:07 volumio volumio[4225]: info: ------------------------------ 18ms Jun 15 18:09:08 volumio volumio[994]: [Vollibrespot] : Event: Volume { volume_to_mixer: 38666 } Jun 15 18:09:08 volumio volumio[4225]: info: Jun 15 18:09:08 volumio volumio[4225]: ---------------------------- MPD announces state update: mixer Jun 15 18:09:08 volumio volumio[4225]: info: ControllerMpd::getState Jun 15 18:09:08 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand status Jun 15 18:09:08 volumio volumio[4225]: info: sending command... Jun 15 18:09:08 volumio volumio[4225]: [SpotifyConnect] Volume Spotify: 59.00053406576639 Volumio: 59 Jun 15 18:09:08 volumio volumio[4225]: info: parsing response... Jun 15 18:09:08 volumio volumio[4225]: info: ControllerMpd::parseState Jun 15 18:09:08 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand playlistinfo Jun 15 18:09:08 volumio volumio[4225]: info: sending command... Jun 15 18:09:08 volumio volumio[4225]: info: parsing response... Jun 15 18:09:08 volumio volumio[4225]: info: ControllerMpd::parseTrackInfo Jun 15 18:09:08 volumio volumio[4225]: info: ControllerMpd::pushState Jun 15 18:09:08 volumio volumio[4225]: info: CoreCommandRouter::servicePushState Jun 15 18:09:08 volumio volumio[4225]: info: CoreStateMachine::syncState Jun 15 18:09:08 volumio volumio[4225]: info: CorePlayQueue::getTrack 23 Jun 15 18:09:08 volumio volumio[4225]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Jun 15 18:09:08 volumio volumio[4225]: info: ------------------------------ 17ms Jun 15 18:09:08 volumio volumio[4225]: info: VolumeController::SetAlsaVolume58 Jun 15 18:09:08 volumio volumio[4225]: info: Jun 15 18:09:08 volumio volumio[4225]: ---------------------------- MPD announces state update: mixer Jun 15 18:09:08 volumio volumio[4225]: info: ControllerMpd::getState Jun 15 18:09:08 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand status Jun 15 18:09:08 volumio volumio[4225]: info: sending command... Jun 15 18:09:08 volumio volumio[4225]: info: parsing response... Jun 15 18:09:08 volumio volumio[4225]: info: ControllerMpd::parseState Jun 15 18:09:08 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand playlistinfo Jun 15 18:09:08 volumio volumio[4225]: info: sending command... Jun 15 18:09:08 volumio volumio[4225]: null Jun 15 18:09:08 volumio volumio[4225]: info: VolumeController::Volume 58 Jun 15 18:09:08 volumio volumio[4225]: info: CoreStateMachine::pushState Jun 15 18:09:08 volumio volumio[4225]: info: CoreStateMachine::getState Jun 15 18:09:08 volumio volumio[4225]: info: CoreCommandRouter::volumioPushState Jun 15 18:09:08 volumio volumio[4225]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 15 18:09:08 volumio volumio[4225]: info: interfaceApi::pushState Jun 15 18:09:08 volumio volumio[4225]: info: parsing response... Jun 15 18:09:08 volumio volumio[4225]: info: ControllerMpd::parseTrackInfo Jun 15 18:09:08 volumio volumio[4225]: info: ControllerMpd::pushState Jun 15 18:09:08 volumio volumio[4225]: info: CoreCommandRouter::servicePushState Jun 15 18:09:08 volumio volumio[4225]: info: CoreStateMachine::syncState Jun 15 18:09:08 volumio volumio[4225]: info: CorePlayQueue::getTrack 23 Jun 15 18:09:08 volumio volumio[4225]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Jun 15 18:09:08 volumio volumio[4225]: info: ------------------------------ 37ms Jun 15 18:09:08 volumio volumio[4225]: info: Pushing Favourites {"service":"spop","uri":"spotify:track:531nFhmDKbyNE3kQLcWMvf","favourite":false} Jun 15 18:09:08 volumio volumio[994]: [Vollibrespot] : Event: Volume { volume_to_mixer: 38011 } Jun 15 18:09:08 volumio volumio[4225]: info: Jun 15 18:09:08 volumio volumio[4225]: ---------------------------- MPD announces state update: mixer Jun 15 18:09:08 volumio volumio[4225]: info: ControllerMpd::getState Jun 15 18:09:08 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand status Jun 15 18:09:08 volumio volumio[4225]: info: sending command... Jun 15 18:09:08 volumio volumio[4225]: info: parsing response... Jun 15 18:09:08 volumio volumio[4225]: info: ControllerMpd::parseState Jun 15 18:09:08 volumio volumio[4225]: info: ControllerMpd::sendMpdCommand playlistinfo Jun 15 18:09:08 volumio volumio[4225]: info: sending command... Jun 15 18:09:08 volumio volumio[4225]: [SpotifyConnect] Volume Spotify: 58.001068131532776 Volumio: 58 Jun 15 18:09:08 volumio volumio[4225]: info: parsing response... Jun 15 18:09:08 volumio volumio[4225]: info: ControllerMpd::parseTrackInfo Jun 15 18:09:08 volumio volumio[4225]: info: ControllerMpd::pushState Jun 15 18:09:08 volumio volumio[4225]: info: CoreCommandRouter::servicePushState Jun 15 18:09:08 volumio volumio[4225]: info: CoreStateMachine::syncState Jun 15 18:09:08 volumio volumio[4225]: info: CorePlayQueue::getTrack 23 Jun 15 18:09:08 volumio volumio[4225]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Jun 15 18:09:08 volumio volumio[4225]: info: ------------------------------ 9ms Jun 15 18:09:11 volumio volumio[4225]: info: CoreCommandRouter::volumioPause Jun 15 18:09:11 volumio volumio[4225]: info: CoreStateMachine::pause Jun 15 18:09:12 volumio volumio[4225]: info: CoreCommandRouter::volumioPause Jun 15 18:09:12 volumio volumio[4225]: info: CoreStateMachine::pause Jun 15 18:09:12 volumio volumio[4225]: info: CoreCommandRouter::volumioPause Jun 15 18:09:12 volumio volumio[4225]: info: CoreStateMachine::pause Jun 15 18:09:15 volumio volumio[4225]: info: CoreCommandRouter::volumioPause Jun 15 18:09:15 volumio volumio[4225]: info: CoreStateMachine::pause Jun 15 18:09:15 volumio volumio[4225]: info: CoreCommandRouter::volumioPause Jun 15 18:09:15 volumio volumio[4225]: info: CoreStateMachine::pause Jun 15 18:09:16 volumio volumio[4225]: info: CoreCommandRouter::volumioNext Jun 15 18:09:16 volumio volumio[4225]: info: CoreStateMachine::next Jun 15 18:09:16 volumio volumio[4225]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 15 18:09:16 volumio volumio[4225]: TypeError: Cannot read property 'next' of undefined Jun 15 18:09:16 volumio volumio[4225]: at CoreStateMachine.next (/volumio/app/statemachine.js:1196:18) Jun 15 18:09:16 volumio volumio[4225]: at CoreCommandRouter.volumioNext (/volumio/app/index.js:112:27) Jun 15 18:09:16 volumio volumio[4225]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:242:36) Jun 15 18:09:16 volumio volumio[4225]: at emitTwo (events.js:126:13) Jun 15 18:09:16 volumio volumio[4225]: at Socket.emit (events.js:214:7) Jun 15 18:09:16 volumio volumio[4225]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Jun 15 18:09:16 volumio volumio[4225]: at _combinedTickCallback (internal/process/next_tick.js:131:7) Jun 15 18:09:16 volumio volumio[4225]: at process._tickCallback (internal/process/next_tick.js:180:9) Jun 15 18:09:16 volumio volumio[4225]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 15 18:09:16 volumio sudo[5979]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-15 18:08 Jun 15 18:09:16 volumio sudo[5979]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 8 (jessie)" NAME="Raspbian GNU/Linux" VERSION_ID="8" VERSION="8 (jessie)" 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="d0d14b37ffe8e45861e4e0b9816241fbafb4eb91" VOLUMIO_FE_VERSION="81c7100e9c7342b16fc9e0ca5908a26771e08c4f" VOLUMIO_BE_VERSION="645f0e55945bdd625a662a1ee21ba0dfb11bd73e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Jun 21 01:30:10 CEST 2018" VOLUMIO_VERSION="2.413" VOLUMIO_HARDWARE="pi"