-- Logs begin at Thu 2024-03-28 16:28:09 UTC, end at Sat 2024-05-04 07:31:37 UTC. -- May 04 07:30:22 volumio volumio[1025]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 May 04 07:30:53 volumio volumio[1215]: [Vollibrespot] : Event: Pause { track_id: SpotifyId { id: 86368950605488649814737170083758521153, audio_type: Track }, position_ms: 211245 } May 04 07:30:53 volumio volumio[1025]: [SpotifyConnect] pause May 04 07:30:53 volumio volumio[1025]: [SpotifyConnect] Days Like These May 04 07:30:53 volumio volumio[1025]: info: [1714807853646] ControllerSpotify::pushState May 04 07:30:53 volumio volumio[1025]: info: CoreCommandRouter::servicePushState May 04 07:30:53 volumio volumio[1025]: info: CoreStateMachine::pushState May 04 07:30:53 volumio volumio[1025]: info: CoreCommandRouter::volumioPushState May 04 07:30:53 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:30:54 volumio volumio[1215]: [Vollibrespot] : Event: SinkInactive May 04 07:30:54 volumio volumio[1215]: [Vollibrespot] : Event: PlaybackStopped { track_id: SpotifyId { id: 86368950605488649814737170083758521153, audio_type: Track } } May 04 07:30:54 volumio volumio[1025]: [SpotifyConnect] Sink released May 04 07:30:54 volumio volumio[1025]: info: [1714807854000] ControllerSpotify::pushState May 04 07:30:54 volumio volumio[1025]: info: CoreCommandRouter::servicePushState May 04 07:30:54 volumio volumio[1025]: info: CoreStateMachine::pushState May 04 07:30:54 volumio volumio[1025]: info: CoreCommandRouter::volumioPushState May 04 07:30:54 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:30:54 volumio volumio[1025]: info: CorePlayQueue::getTrack 3 May 04 07:30:54 volumio volumio[1025]: verbose: STATE SERVICE {"status":"stop","service":"spop","title":"Days Like These","artist":"The Cat Empire","album":"The Cat Empire","albumart":"https://i.scdn.co/image/ab67616d0000b27353f8172e38162a452d6cdaee","uri":"spotify:track:1YBMCQSgStD1xvQZuFphjr","trackType":"spotify","seek":211245,"duration":248,"samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","channels":2,"stream":false,"repeatMode":"all"} May 04 07:30:54 volumio volumio[1025]: verbose: CURRENT POSITION 3 May 04 07:30:54 volumio volumio[1025]: info: CoreStateMachine::syncState stateService stop May 04 07:30:54 volumio volumio[1025]: info: CoreStateMachine::syncState currentStatus play May 04 07:30:54 volumio volumio[1025]: info: CoreStateMachine::play index undefined May 04 07:30:54 volumio volumio[1025]: info: CoreStateMachine::setConsumeUpdateService undefined May 04 07:30:54 volumio volumio[1025]: info: CoreStateMachine::pushState May 04 07:30:54 volumio volumio[1025]: info: CoreCommandRouter::volumioPushState May 04 07:30:54 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:30:54 volumio volumio[1025]: info: CorePlayQueue::getTrack 4 May 04 07:30:54 volumio volumio[1025]: info: CoreStateMachine::startPlaybackTimer May 04 07:30:54 volumio volumio[1025]: info: CorePlayQueue::getTrack 4 May 04 07:30:54 volumio volumio[1025]: info: [1714807854031] ControllerSpotify::clearAddPlayTrack May 04 07:30:54 volumio volumio[1025]: info: Setting this device active May 04 07:30:54 volumio volumio[1025]: info: CoreStateMachine::pushState May 04 07:30:54 volumio volumio[1025]: info: CoreCommandRouter::volumioPushState May 04 07:30:54 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:30:54 volumio volumio[1025]: [SpotifyConnect] Device palyback is inactive May 04 07:30:54 volumio volumio[1215]: [Vollibrespot] : Fetching autoplay context uri May 04 07:30:54 volumio volumio[1215]: [Vollibrespot] : Event: TrackChanged { old_track_id: SpotifyId { id: 86368950605488649814737170083758521153, audio_type: Track }, track_id: SpotifyId { id: 86368950605488649814737170083758521153, audio_type: Track } } May 04 07:30:54 volumio volumio[1215]: [Vollibrespot] : error 400 for uri hm://autoplay-enabled/query?uri= May 04 07:30:54 volumio volumio[1215]: [Vollibrespot] : AutoplayError: MercuryError May 04 07:30:54 volumio volumio[1215]: [Vollibrespot] : Event: PlaybackStopped { track_id: SpotifyId { id: 86368950605488649814737170083758521153, audio_type: Track } } May 04 07:30:54 volumio volumio[1025]: [SpotifyConnect] Days Like These May 04 07:30:54 volumio volumio[1025]: info: [1714807854506] ControllerSpotify::pushState May 04 07:30:54 volumio volumio[1025]: info: CoreCommandRouter::servicePushState May 04 07:30:54 volumio volumio[1025]: info: CoreStateMachine::pushState May 04 07:30:54 volumio volumio[1025]: info: CoreCommandRouter::volumioPushState May 04 07:30:54 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:30:54 volumio volumio[1025]: info: CorePlayQueue::getTrack 4 May 04 07:30:54 volumio volumio[1025]: verbose: STATE SERVICE {"status":"stop","service":"spop","title":"Days Like These","artist":"The Cat Empire","album":"The Cat Empire","albumart":"https://i.scdn.co/image/ab67616d0000b27353f8172e38162a452d6cdaee","uri":"spotify:track:1YBMCQSgStD1xvQZuFphjr","trackType":"spotify","seek":0,"duration":248,"samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","channels":2,"stream":false,"repeatMode":"all"} May 04 07:30:54 volumio volumio[1025]: verbose: CURRENT POSITION 4 May 04 07:30:54 volumio volumio[1025]: info: CoreStateMachine::syncState stateService stop May 04 07:30:54 volumio volumio[1025]: info: CoreStateMachine::syncState currentStatus stop May 04 07:30:54 volumio volumio[1025]: info: CoreStateMachine::pushState May 04 07:30:54 volumio volumio[1025]: info: CoreCommandRouter::volumioPushState May 04 07:30:54 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:30:54 volumio volumio[1025]: info: No code May 04 07:30:54 volumio volumio[1025]: info: CoreStateMachine::pushState May 04 07:30:54 volumio volumio[1025]: info: CoreCommandRouter::volumioPushState May 04 07:30:54 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:30:54 volumio volumio[1025]: [SpotifyConnect] Device palyback is inactive May 04 07:30:54 volumio volumio[1215]: [Vollibrespot] : Fetching autoplay context uri May 04 07:30:54 volumio volumio[1215]: [Vollibrespot] : Event: TrackChanged { old_track_id: SpotifyId { id: 86368950605488649814737170083758521153, audio_type: Track }, track_id: SpotifyId { id: 307302836055804856183877872496156796510, audio_type: Track } } May 04 07:30:54 volumio volumio[1215]: [Vollibrespot] : error 400 for uri hm://autoplay-enabled/query?uri= May 04 07:30:54 volumio volumio[1215]: [Vollibrespot] : AutoplayError: MercuryError May 04 07:30:54 volumio volumio[1215]: [Vollibrespot] : Loading with Spotify URI May 04 07:30:54 volumio volumio[1215]: [Vollibrespot] : (195800 ms) loaded May 04 07:30:54 volumio volumio[1215]: [Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 307302836055804856183877872496156796510, audio_type: Track } } May 04 07:30:54 volumio volumio[1025]: [SpotifyConnect] The Lost Song May 04 07:30:54 volumio volumio[1215]: [Vollibrespot] : Event: SinkActive May 04 07:30:54 volumio volumio[1025]: [SpotifyConnect] Sink acquired May 04 07:30:54 volumio volumio[1025]: info: Continuing Spotify Session May 04 07:30:54 volumio volumio[1025]: info: Checking Spotify Web API May 04 07:30:55 volumio volumio[1025]: info: Is Not Connect Playback May 04 07:30:55 volumio volumio[1025]: info: [1714807855716] ControllerSpotify::pushState May 04 07:30:55 volumio volumio[1025]: info: CoreCommandRouter::servicePushState May 04 07:30:55 volumio volumio[1025]: info: CoreStateMachine::pushState May 04 07:30:55 volumio volumio[1025]: info: CoreCommandRouter::volumioPushState May 04 07:30:55 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:30:56 volumio volumio[1215]: [Vollibrespot] : Event: Pause { track_id: SpotifyId { id: 307302836055804856183877872496156796510, audio_type: Track }, position_ms: 2154 } May 04 07:30:56 volumio volumio[1025]: [SpotifyConnect] pause May 04 07:30:57 volumio volumio[1025]: [SpotifyConnect] The Lost Song May 04 07:30:57 volumio volumio[1025]: info: [1714807857148] ControllerSpotify::pushState May 04 07:30:57 volumio volumio[1025]: info: CoreCommandRouter::servicePushState May 04 07:30:57 volumio volumio[1025]: info: CoreStateMachine::pushState May 04 07:30:57 volumio volumio[1025]: info: CoreCommandRouter::volumioPushState May 04 07:30:57 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:30:57 volumio volumio[1215]: [Vollibrespot] : Event: SinkInactive May 04 07:30:57 volumio volumio[1215]: [Vollibrespot] : Event: PlaybackStopped { track_id: SpotifyId { id: 307302836055804856183877872496156796510, audio_type: Track } } May 04 07:30:57 volumio volumio[1025]: [SpotifyConnect] Sink released May 04 07:30:57 volumio volumio[1025]: info: [1714807857566] ControllerSpotify::pushState May 04 07:30:57 volumio volumio[1025]: info: CoreCommandRouter::servicePushState May 04 07:30:57 volumio volumio[1025]: info: CoreStateMachine::pushState May 04 07:30:57 volumio volumio[1025]: info: CoreCommandRouter::volumioPushState May 04 07:30:57 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:30:57 volumio volumio[1025]: info: CorePlayQueue::getTrack 4 May 04 07:30:57 volumio volumio[1025]: verbose: STATE SERVICE {"status":"stop","service":"spop","title":"The Lost Song","artist":"The Cat Empire","album":"The Cat Empire","albumart":"https://i.scdn.co/image/ab67616d0000b27353f8172e38162a452d6cdaee","uri":"spotify:track:72fkIO8SD7tKZ9jiiF0Jyu","trackType":"spotify","seek":2154,"duration":196,"samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","channels":2,"stream":false,"repeatMode":"all"} May 04 07:30:57 volumio volumio[1025]: verbose: CURRENT POSITION 4 May 04 07:30:57 volumio volumio[1025]: info: CoreStateMachine::syncState stateService stop May 04 07:30:57 volumio volumio[1025]: info: CoreStateMachine::syncState currentStatus play May 04 07:30:57 volumio volumio[1025]: info: CoreStateMachine::play index undefined May 04 07:30:57 volumio volumio[1025]: info: CoreStateMachine::setConsumeUpdateService undefined May 04 07:30:57 volumio volumio[1025]: info: CoreStateMachine::pushState May 04 07:30:57 volumio volumio[1025]: info: CoreCommandRouter::volumioPushState May 04 07:30:57 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:30:57 volumio volumio[1025]: info: CorePlayQueue::getTrack 5 May 04 07:30:57 volumio volumio[1025]: info: CoreStateMachine::startPlaybackTimer May 04 07:30:57 volumio volumio[1025]: info: CorePlayQueue::getTrack 5 May 04 07:30:57 volumio volumio[1025]: info: [1714807857603] ControllerSpotify::clearAddPlayTrack May 04 07:30:57 volumio volumio[1025]: info: Setting this device active May 04 07:30:57 volumio volumio[1025]: info: CoreStateMachine::pushState May 04 07:30:57 volumio volumio[1025]: info: CoreCommandRouter::volumioPushState May 04 07:30:57 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:30:57 volumio volumio[1025]: [SpotifyConnect] Device palyback is inactive May 04 07:30:57 volumio volumio[1215]: [Vollibrespot] : Fetching autoplay context uri May 04 07:30:57 volumio volumio[1215]: [Vollibrespot] : Event: TrackChanged { old_track_id: SpotifyId { id: 307302836055804856183877872496156796510, audio_type: Track }, track_id: SpotifyId { id: 307302836055804856183877872496156796510, audio_type: Track } } May 04 07:30:57 volumio volumio[1215]: [Vollibrespot] : error 400 for uri hm://autoplay-enabled/query?uri= May 04 07:30:57 volumio volumio[1215]: [Vollibrespot] : AutoplayError: MercuryError May 04 07:30:58 volumio volumio[1025]: [SpotifyConnect] The Lost Song May 04 07:30:58 volumio volumio[1025]: info: [1714807858110] ControllerSpotify::pushState May 04 07:30:58 volumio volumio[1025]: info: CoreCommandRouter::servicePushState May 04 07:30:58 volumio volumio[1025]: info: CoreStateMachine::pushState May 04 07:30:58 volumio volumio[1215]: [Vollibrespot] : Event: PlaybackStopped { track_id: SpotifyId { id: 307302836055804856183877872496156796510, audio_type: Track } } May 04 07:30:58 volumio volumio[1025]: info: CoreCommandRouter::volumioPushState May 04 07:30:58 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:30:58 volumio volumio[1025]: info: CorePlayQueue::getTrack 5 May 04 07:30:58 volumio volumio[1025]: verbose: STATE SERVICE {"status":"stop","service":"spop","title":"The Lost Song","artist":"The Cat Empire","album":"The Cat Empire","albumart":"https://i.scdn.co/image/ab67616d0000b27353f8172e38162a452d6cdaee","uri":"spotify:track:72fkIO8SD7tKZ9jiiF0Jyu","trackType":"spotify","seek":0,"duration":196,"samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","channels":2,"stream":false,"repeatMode":"all"} May 04 07:30:58 volumio volumio[1025]: verbose: CURRENT POSITION 5 May 04 07:30:58 volumio volumio[1025]: info: CoreStateMachine::syncState stateService stop May 04 07:30:58 volumio volumio[1025]: info: CoreStateMachine::syncState currentStatus stop May 04 07:30:58 volumio volumio[1025]: info: CoreStateMachine::pushState May 04 07:30:58 volumio volumio[1025]: info: CoreCommandRouter::volumioPushState May 04 07:30:58 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:30:58 volumio volumio[1025]: info: No code May 04 07:30:58 volumio volumio[1025]: info: CoreStateMachine::pushState May 04 07:30:58 volumio volumio[1025]: info: CoreCommandRouter::volumioPushState May 04 07:30:58 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:30:58 volumio volumio[1025]: [SpotifyConnect] Device palyback is inactive May 04 07:30:58 volumio volumio[1215]: [Vollibrespot] : Fetching autoplay context uri May 04 07:30:58 volumio volumio[1215]: [Vollibrespot] : Event: TrackChanged { old_track_id: SpotifyId { id: 307302836055804856183877872496156796510, audio_type: Track }, track_id: SpotifyId { id: 17780751643053532758615792320061504272, audio_type: Track } } May 04 07:30:58 volumio volumio[1215]: [Vollibrespot] : error 400 for uri hm://autoplay-enabled/query?uri= May 04 07:30:58 volumio volumio[1215]: [Vollibrespot] : AutoplayError: MercuryError May 04 07:30:58 volumio volumio[1215]: [Vollibrespot] : Loading with Spotify URI May 04 07:30:58 volumio volumio[1215]: [Vollibrespot] : (334360 ms) loaded May 04 07:30:58 volumio volumio[1215]: [Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 17780751643053532758615792320061504272, audio_type: Track } } May 04 07:30:58 volumio volumio[1215]: [Vollibrespot] : Event: SinkActive May 04 07:30:58 volumio volumio[1025]: [SpotifyConnect] The Chariot May 04 07:30:58 volumio volumio[1025]: [SpotifyConnect] Sink acquired May 04 07:30:58 volumio volumio[1025]: info: Continuing Spotify Session May 04 07:30:58 volumio volumio[1025]: info: Checking Spotify Web API May 04 07:30:59 volumio volumio[1025]: info: Is Not Connect Playback May 04 07:30:59 volumio volumio[1025]: info: [1714807859327] ControllerSpotify::pushState May 04 07:30:59 volumio volumio[1025]: info: CoreCommandRouter::servicePushState May 04 07:30:59 volumio volumio[1025]: info: CoreStateMachine::pushState May 04 07:30:59 volumio volumio[1025]: info: CoreCommandRouter::volumioPushState May 04 07:30:59 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:30:59 volumio volumio[1215]: [Vollibrespot] : Event: Pause { track_id: SpotifyId { id: 17780751643053532758615792320061504272, audio_type: Track }, position_ms: 1570 } May 04 07:30:59 volumio volumio[1025]: [SpotifyConnect] pause May 04 07:31:00 volumio volumio[1025]: [SpotifyConnect] The Chariot May 04 07:31:00 volumio volumio[1025]: info: [1714807860331] ControllerSpotify::pushState May 04 07:31:00 volumio volumio[1025]: info: CoreCommandRouter::servicePushState May 04 07:31:00 volumio volumio[1025]: info: CoreStateMachine::pushState May 04 07:31:00 volumio volumio[1025]: info: CoreCommandRouter::volumioPushState May 04 07:31:00 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:31:00 volumio volumio[1215]: [Vollibrespot] : Event: SinkInactive May 04 07:31:00 volumio volumio[1215]: [Vollibrespot] : Event: PlaybackStopped { track_id: SpotifyId { id: 17780751643053532758615792320061504272, audio_type: Track } } May 04 07:31:00 volumio volumio[1025]: [SpotifyConnect] Sink released May 04 07:31:00 volumio volumio[1025]: info: [1714807860685] ControllerSpotify::pushState May 04 07:31:00 volumio volumio[1025]: info: CoreCommandRouter::servicePushState May 04 07:31:00 volumio volumio[1025]: info: CoreStateMachine::pushState May 04 07:31:00 volumio volumio[1025]: info: CoreCommandRouter::volumioPushState May 04 07:31:00 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:31:00 volumio volumio[1025]: info: CorePlayQueue::getTrack 5 May 04 07:31:00 volumio volumio[1025]: verbose: STATE SERVICE {"status":"stop","service":"spop","title":"The Chariot","artist":"The Cat Empire","album":"The Cat Empire","albumart":"https://i.scdn.co/image/ab67616d0000b27353f8172e38162a452d6cdaee","uri":"spotify:track:0peYAmI5sjt67CFMgmUfjq","trackType":"spotify","seek":1570,"duration":335,"samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","channels":2,"stream":false,"repeatMode":"all"} May 04 07:31:00 volumio volumio[1025]: verbose: CURRENT POSITION 5 May 04 07:31:00 volumio volumio[1025]: info: CoreStateMachine::syncState stateService stop May 04 07:31:00 volumio volumio[1025]: info: CoreStateMachine::syncState currentStatus play May 04 07:31:00 volumio volumio[1025]: info: CoreStateMachine::play index undefined May 04 07:31:00 volumio volumio[1025]: info: CoreStateMachine::setConsumeUpdateService undefined May 04 07:31:00 volumio volumio[1025]: info: CoreStateMachine::pushState May 04 07:31:00 volumio volumio[1025]: info: CoreCommandRouter::volumioPushState May 04 07:31:00 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:31:00 volumio volumio[1025]: info: CorePlayQueue::getTrack 6 May 04 07:31:00 volumio volumio[1025]: info: CoreStateMachine::startPlaybackTimer May 04 07:31:00 volumio volumio[1025]: info: CorePlayQueue::getTrack 6 May 04 07:31:00 volumio volumio[1025]: info: [1714807860721] ControllerSpotify::clearAddPlayTrack May 04 07:31:00 volumio volumio[1025]: info: Setting this device active May 04 07:31:00 volumio volumio[1025]: info: CoreStateMachine::pushState May 04 07:31:00 volumio volumio[1025]: info: CoreCommandRouter::volumioPushState May 04 07:31:00 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:31:00 volumio volumio[1025]: [SpotifyConnect] Device palyback is inactive May 04 07:31:01 volumio volumio[1215]: [Vollibrespot] : Fetching autoplay context uri May 04 07:31:01 volumio volumio[1215]: [Vollibrespot] : Event: TrackChanged { old_track_id: SpotifyId { id: 17780751643053532758615792320061504272, audio_type: Track }, track_id: SpotifyId { id: 17780751643053532758615792320061504272, audio_type: Track } } May 04 07:31:01 volumio volumio[1215]: [Vollibrespot] : error 400 for uri hm://autoplay-enabled/query?uri= May 04 07:31:01 volumio volumio[1215]: [Vollibrespot] : AutoplayError: MercuryError May 04 07:31:01 volumio volumio[1025]: [SpotifyConnect] The Chariot May 04 07:31:01 volumio volumio[1025]: info: [1714807861333] ControllerSpotify::pushState May 04 07:31:01 volumio volumio[1025]: info: CoreCommandRouter::servicePushState May 04 07:31:01 volumio volumio[1025]: info: CoreStateMachine::pushState May 04 07:31:01 volumio volumio[1025]: info: CoreCommandRouter::volumioPushState May 04 07:31:01 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:31:01 volumio volumio[1025]: info: CorePlayQueue::getTrack 6 May 04 07:31:01 volumio volumio[1025]: verbose: STATE SERVICE {"status":"stop","service":"spop","title":"The Chariot","artist":"The Cat Empire","album":"The Cat Empire","albumart":"https://i.scdn.co/image/ab67616d0000b27353f8172e38162a452d6cdaee","uri":"spotify:track:0peYAmI5sjt67CFMgmUfjq","trackType":"spotify","seek":0,"duration":335,"samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","channels":2,"stream":false,"repeatMode":"all"} May 04 07:31:01 volumio volumio[1215]: [Vollibrespot] : Event: PlaybackStopped { track_id: SpotifyId { id: 17780751643053532758615792320061504272, audio_type: Track } } May 04 07:31:01 volumio volumio[1025]: verbose: CURRENT POSITION 6 May 04 07:31:01 volumio volumio[1025]: info: CoreStateMachine::syncState stateService stop May 04 07:31:01 volumio volumio[1025]: info: CoreStateMachine::syncState currentStatus stop May 04 07:31:01 volumio volumio[1025]: info: CoreStateMachine::pushState May 04 07:31:01 volumio volumio[1025]: info: CoreCommandRouter::volumioPushState May 04 07:31:01 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:31:01 volumio volumio[1025]: info: No code May 04 07:31:01 volumio volumio[1025]: info: CoreStateMachine::pushState May 04 07:31:01 volumio volumio[1025]: info: CoreCommandRouter::volumioPushState May 04 07:31:01 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:31:01 volumio volumio[1025]: [SpotifyConnect] Device palyback is inactive May 04 07:31:01 volumio volumio[1215]: [Vollibrespot] : Fetching autoplay context uri May 04 07:31:01 volumio volumio[1215]: [Vollibrespot] : Event: TrackChanged { old_track_id: SpotifyId { id: 17780751643053532758615792320061504272, audio_type: Track }, track_id: SpotifyId { id: 61960659025828689913265431438706077823, audio_type: Track } } May 04 07:31:01 volumio volumio[1215]: [Vollibrespot] : error 400 for uri hm://autoplay-enabled/query?uri= May 04 07:31:01 volumio volumio[1215]: [Vollibrespot] : AutoplayError: MercuryError May 04 07:31:01 volumio volumio[1215]: [Vollibrespot] : Loading with Spotify URI May 04 07:31:01 volumio volumio[1215]: [Vollibrespot] : (224133 ms) loaded May 04 07:31:01 volumio volumio[1215]: [Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 61960659025828689913265431438706077823, audio_type: Track } } May 04 07:31:01 volumio volumio[1215]: [Vollibrespot] : Event: SinkActive May 04 07:31:01 volumio volumio[1025]: [SpotifyConnect] Hello May 04 07:31:01 volumio volumio[1025]: [SpotifyConnect] Sink acquired May 04 07:31:01 volumio volumio[1025]: info: Continuing Spotify Session May 04 07:31:01 volumio volumio[1025]: info: Checking Spotify Web API May 04 07:31:02 volumio volumio[1025]: info: Is Not Connect Playback May 04 07:31:02 volumio volumio[1025]: info: [1714807862405] ControllerSpotify::pushState May 04 07:31:02 volumio volumio[1025]: info: CoreCommandRouter::servicePushState May 04 07:31:02 volumio volumio[1025]: info: CoreStateMachine::pushState May 04 07:31:02 volumio volumio[1025]: info: CoreCommandRouter::volumioPushState May 04 07:31:02 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:31:14 volumio kernel: Under-voltage detected! (0x00050005) May 04 07:31:15 volumio sudo[1408]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 04 07:31:15 volumio sudo[1408]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:31:15 volumio sudo[1410]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 04 07:31:15 volumio sudo[1408]: pam_unix(sudo:session): session closed for user root May 04 07:31:15 volumio sudo[1410]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:31:15 volumio sudo[1410]: pam_unix(sudo:session): session closed for user root May 04 07:31:15 volumio volumio[1025]: info: CoreCommandRouter::volumioGetVisibleSources May 04 07:31:15 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 07:31:15 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 04 07:31:15 volumio volumio[1025]: info: CoreCommandRouter::volumioGetState May 04 07:31:15 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 04 07:31:15 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 04 07:31:15 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 04 07:31:15 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 04 07:31:15 volumio sudo[1431]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 04 07:31:15 volumio sudo[1431]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:31:15 volumio sudo[1433]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 04 07:31:15 volumio sudo[1431]: pam_unix(sudo:session): session closed for user root May 04 07:31:15 volumio sudo[1433]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 07:31:15 volumio sudo[1433]: pam_unix(sudo:session): session closed for user root May 04 07:31:16 volumio volumio[1025]: info: CoreCommandRouter::volumioGetState May 04 07:31:16 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 04 07:31:16 volumio volumio[1025]: info: Listing playlists May 04 07:31:16 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 04 07:31:16 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 04 07:31:16 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 04 07:31:16 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 04 07:31:17 volumio volumio[1025]: info: CoreCommandRouter::volumioPause May 04 07:31:17 volumio volumio[1025]: info: CoreStateMachine::pause May 04 07:31:17 volumio volumio[1025]: info: CoreStateMachine::stPlaybackTimer May 04 07:31:17 volumio volumio[1025]: info: CoreStateMachine::servicePause May 04 07:31:17 volumio volumio[1025]: info: CoreCommandRouter::servicePause May 04 07:31:17 volumio volumio[1025]: info: Spotify Received pause May 04 07:31:17 volumio volumio[1215]: [Vollibrespot] : Event: Pause { track_id: SpotifyId { id: 61960659025828689913265431438706077823, audio_type: Track }, position_ms: 15855 } May 04 07:31:17 volumio volumio[1025]: [SpotifyConnect] pause May 04 07:31:17 volumio volumio[1025]: info: [1714807877507] ControllerSpotify::pushState May 04 07:31:17 volumio volumio[1025]: info: CoreCommandRouter::servicePushState May 04 07:31:17 volumio volumio[1025]: info: CoreStateMachine::pushState May 04 07:31:17 volumio volumio[1025]: info: CoreCommandRouter::volumioPushState May 04 07:31:17 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:31:17 volumio volumio[1025]: [SpotifyConnect] Hello May 04 07:31:17 volumio volumio[1025]: info: [1714807877903] ControllerSpotify::pushState May 04 07:31:17 volumio volumio[1025]: info: CoreCommandRouter::servicePushState May 04 07:31:17 volumio volumio[1025]: info: CoreStateMachine::pushState May 04 07:31:17 volumio volumio[1025]: info: CoreCommandRouter::volumioPushState May 04 07:31:17 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:31:18 volumio volumio[1215]: [Vollibrespot] : Event: SinkInactive May 04 07:31:18 volumio volumio[1215]: [Vollibrespot] : Event: PlaybackStopped { track_id: SpotifyId { id: 61960659025828689913265431438706077823, audio_type: Track } } May 04 07:31:18 volumio volumio[1025]: [SpotifyConnect] Sink released May 04 07:31:18 volumio volumio[1025]: info: [1714807878160] ControllerSpotify::pushState May 04 07:31:18 volumio volumio[1025]: info: CoreCommandRouter::servicePushState May 04 07:31:18 volumio volumio[1025]: info: CoreStateMachine::pushState May 04 07:31:18 volumio volumio[1025]: info: CoreCommandRouter::volumioPushState May 04 07:31:18 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:31:18 volumio volumio[1025]: [SpotifyConnect] Device palyback is inactive May 04 07:31:19 volumio volumio[1025]: info: CoreCommandRouter::volumioGetVisibleSources May 04 07:31:19 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 07:31:19 volumio volumio[1025]: info: CoreCommandRouter::volumioGetQueue May 04 07:31:19 volumio volumio[1025]: info: CoreStateMachine::getQueue May 04 07:31:19 volumio volumio[1025]: info: CorePlayQueue::getQueue May 04 07:31:20 volumio kernel: Voltage normalised (0x00000000) May 04 07:31:23 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 04 07:31:23 volumio volumio[1025]: info: In handleBrowseUri, curUri=spotify May 04 07:31:35 volumio volumio[1025]: Searching all installed plugins May 04 07:31:35 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 07:31:35 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: , search May 04 07:31:35 volumio volumio[1025]: info: CoreCommandRouter::executeOnPlugin: mpd , search May 04 07:31:35 volumio volumio[1025]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 04 07:31:35 volumio volumio[1025]: TypeError: Cannot read property 'then' of undefined May 04 07:31:35 volumio volumio[1025]: at ControllerMpd.search (/volumio/app/plugins/music_service/mpd/index.js:1516:17) May 04 07:31:35 volumio volumio[1025]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1063:32) May 04 07:31:35 volumio volumio[1025]: at CoreMusicLibrary.searchOnPlugin (/volumio/app/musiclibrary.js:649:44) May 04 07:31:35 volumio volumio[1025]: at CoreMusicLibrary.search (/volumio/app/musiclibrary.js:451:27) May 04 07:31:35 volumio volumio[1025]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:406:44) May 04 07:31:35 volumio volumio[1025]: at emitTwo (events.js:126:13) May 04 07:31:35 volumio volumio[1025]: at Socket.emit (events.js:214:7) May 04 07:31:35 volumio volumio[1025]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 May 04 07:31:35 volumio volumio[1025]: at _combinedTickCallback (internal/process/next_tick.js:131:7) May 04 07:31:35 volumio volumio[1025]: at process._tickCallback (internal/process/next_tick.js:180:9) May 04 07:31:35 volumio volumio[1025]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 04 07:31:37 volumio sudo[1474]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-05-04 07:30 May 04 07:31:37 volumio sudo[1474]: 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="b9cd485c2d7861a79d18f42ff0fdb052338b2239" VOLUMIO_FE_VERSION="2932a2aa65665ab9ec21cd0bdf3d21669bbbf643" VOLUMIO_BE_VERSION="8583c814bdc88e8c28c10464bec8226bce2b0634" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon May 25 18:53:02 CEST 2020" VOLUMIO_VERSION="2.777" VOLUMIO_HARDWARE="pi" VOLUMIO_HASH="c75975235b22f56393d7c4516aa10590"