-- Logs begin at Sat 2024-04-20 11:18:27 UTC, end at Wed 2024-04-24 10:27:38 UTC. -- Apr 24 10:26:53 volumio volumio[959]: [Vollibrespot] : Event: SessionActive { became_active_at: 1713954412321 } Apr 24 10:26:53 volumio volumio[959]: [Vollibrespot] : SessionActive! Apr 24 10:26:53 volumio volumio[834]: [SpotifyConnect] A connect session has begun Apr 24 10:26:53 volumio volumio[834]: info: Acquiring new spotify session Apr 24 10:26:53 volumio volumio[834]: info: CoreCommandRouter::volumioStop Apr 24 10:26:53 volumio volumio[834]: info: CoreStateMachine::stop Apr 24 10:26:53 volumio volumio[959]: [Vollibrespot] : Fetching autoplay context uri Apr 24 10:26:53 volumio volumio[959]: [Vollibrespot] : Event: PlaybackStarted { track_id: SpotifyId { id: 22082834301704912600517248283192828877, audio_type: Track } } Apr 24 10:26:53 volumio volumio[959]: [Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 22082834301704912600517248283192828877, audio_type: Track } } Apr 24 10:26:53 volumio volumio[834]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 24 10:26:53 volumio volumio[834]: UNSET VOLATILE Apr 24 10:26:53 volumio volumio[834]: info: Checking Spotify Web API Apr 24 10:26:53 volumio volumio[834]: [SpotifyConnect] Vollibrespot Active Apr 24 10:26:53 volumio volumio[834]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 24 10:26:53 volumio volumio[834]: info: [1713954413331] ControllerSpotify::pushState Apr 24 10:26:53 volumio volumio[834]: info: CoreCommandRouter::servicePushState Apr 24 10:26:53 volumio volumio[834]: info: CoreStateMachine::syncState Apr 24 10:26:53 volumio volumio[834]: info: CoreStateMachine::pushState Apr 24 10:26:53 volumio volumio[834]: info: CoreStateMachine::getState Apr 24 10:26:53 volumio volumio[834]: info: CoreCommandRouter::volumioPushState Apr 24 10:26:53 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 24 10:26:53 volumio volumio[834]: info: interfaceApi::pushState Apr 24 10:26:53 volumio volumio[959]: [Vollibrespot] : Autoplay uri resolved to <"spotify:station:playlist:37i9dQZF1EQpj7X7UK8OOF"> Apr 24 10:26:53 volumio volumio[959]: [Vollibrespot] : Resolving uri "spotify:station:playlist:37i9dQZF1EQpj7X7UK8OOF" Apr 24 10:26:53 volumio volumio[834]: [SpotifyConnect] Device palyback is active! Apr 24 10:26:53 volumio volumio[834]: info: Pushing Favourites {"service":"spop","uri":"","favourite":false} Apr 24 10:26:53 volumio volumio[959]: [Vollibrespot] : Event: GotToken { token: Token { access_token: "BQB6N2MA0TumLoCSefkBWC0k1mbxezzuI0BQjeAWik4QJH3EWzohyRPw6AOhTuoXZ8cnl0vk8EN9oNm70ECTWDQDYEg-jgdU7WPZgZiGuaiis2eUJyfyP9ni7v618PrFc-KTLoc25UFj5KA8koJDxHx7Q-7j7IweNHRMz3HU833P6MrQdvkz9KjXdeNKfdyjsbR5v5l2TJCGboa8xC9KxvkA-2RcDg", expires_in: 3600, token_type: "Bearer", scope: ["streaming", "user-read-playback-state", "user-modify-playback-state", "user-read-currently-playing", "user-read-private"] } } Apr 24 10:26:53 volumio volumio[959]: [Vollibrespot] : Loading with Spotify URI Apr 24 10:26:53 volumio volumio[834]: info: New Spotify Access Token Received Apr 24 10:26:53 volumio volumio[834]: info: Initializing Spotify Web API Apr 24 10:26:53 volumio volumio[834]: info: Initliazing Spotify Browsing Facility Apr 24 10:26:53 volumio volumio[834]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 24 10:26:53 volumio volumio[834]: info: [1713954413402] CoreMusicLibrary::Adding element Spotify Apr 24 10:26:53 volumio volumio[959]: [Vollibrespot] : (324200 ms) loaded Apr 24 10:26:53 volumio volumio[959]: [Vollibrespot] : Event: SinkActive Apr 24 10:26:53 volumio volumio[834]: [SpotifyConnect] Sink acquired Apr 24 10:26:53 volumio volumio[834]: info: Continuing Spotify Session Apr 24 10:26:53 volumio volumio[834]: info: Checking Spotify Web API Apr 24 10:26:53 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Apr 24 10:26:54 volumio volumio[959]: [Vollibrespot] : Resolved 50 tracks from <"spotify:playlist:37i9dQZF1EQpj7X7UK8OOF"> Apr 24 10:27:36 volumio volumio[959]: [Vollibrespot] : Event: Next { track_id: SpotifyId { id: 13259025644658910527174688479519108662, audio_type: Track } } Apr 24 10:27:37 volumio volumio[959]: [Vollibrespot] : Event: TrackChanged { old_track_id: SpotifyId { id: 22082834301704912600517248283192828877, audio_type: Track }, track_id: SpotifyId { id: 13259025644658910527174688479519108662, audio_type: Track } } Apr 24 10:27:37 volumio volumio[834]: [SpotifyConnect] Mrs. Robinson - From "The Graduate" Soundtrack Apr 24 10:27:37 volumio volumio[959]: [Vollibrespot] : Event: SinkInactive Apr 24 10:27:37 volumio volumio[959]: [Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 13259025644658910527174688479519108662, audio_type: Track } } Apr 24 10:27:37 volumio volumio[834]: [SpotifyConnect] Sink released Apr 24 10:27:37 volumio volumio[834]: info: [1713954457505] ControllerSpotify::pushState Apr 24 10:27:37 volumio volumio[834]: info: CoreCommandRouter::servicePushState Apr 24 10:27:37 volumio volumio[834]: info: CoreStateMachine::syncState Apr 24 10:27:37 volumio volumio[834]: info: CorePlayQueue::getTrack 0 Apr 24 10:27:37 volumio volumio[834]: info: STATE SERVICE {"status":"stop","service":"spop","title":"Mrs. Robinson - From \"The Graduate\" Soundtrack","artist":"Simon & Garfunkel","album":"Bookends","albumart":"https://i.scdn.co/image/ab67616d0000b273d8fb5b4308dc27f210064ef4","uri":"spotify:track:0iOZM63lendWRTTeKhZBSC","trackType":"spotify","seek":0,"duration":245,"samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","channels":2,"stream":false} Apr 24 10:27:37 volumio volumio[834]: info: CURRENT POSITION 0 Apr 24 10:27:37 volumio volumio[834]: info: CoreStateMachine::syncState stateService stop Apr 24 10:27:37 volumio volumio[834]: info: CoreStateMachine::syncState currentStatus play Apr 24 10:27:37 volumio volumio[834]: info: CURRENT POSITION 0 Apr 24 10:27:37 volumio volumio[834]: info: CURRENT POSITION 0 Apr 24 10:27:37 volumio volumio[834]: info: END OF QUEUE Apr 24 10:27:37 volumio volumio[834]: info: CoreStateMachine::pushEmptyState Apr 24 10:27:37 volumio volumio[834]: info: CoreCommandRouter::volumioPushState Apr 24 10:27:37 volumio volumio[834]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 24 10:27:37 volumio volumio[834]: info: interfaceApi::pushState Apr 24 10:27:37 volumio volumio[834]: info: CoreStateMachine::stPlaybackTimer Apr 24 10:27:37 volumio volumio[834]: info: Pushing Favourites {"service":"mpd","uri":"","favourite":false} Apr 24 10:27:37 volumio volumio[959]: [Vollibrespot] : Loading with Spotify URI Apr 24 10:27:37 volumio volumio[959]: [Vollibrespot] : (244026 ms) loaded Apr 24 10:27:37 volumio volumio[959]: [Vollibrespot] : Event: SinkActive Apr 24 10:27:37 volumio volumio[834]: [SpotifyConnect] Sink acquired Apr 24 10:27:37 volumio volumio[834]: info: Acquiring new spotify session Apr 24 10:27:37 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Apr 24 10:27:37 volumio volumio[834]: info: CoreCommandRouter::volumioStop Apr 24 10:27:37 volumio volumio[834]: info: CoreStateMachine::stop Apr 24 10:27:37 volumio volumio[834]: info: CoreStateMachine::serviceStop Apr 24 10:27:37 volumio volumio[834]: info: Received STOP, but no service to execute it Apr 24 10:27:37 volumio volumio[834]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 24 10:27:37 volumio volumio[834]: TypeError: Cannot read property 'then' of undefined Apr 24 10:27:37 volumio volumio[834]: at SpotConnEvents.SpotConn.on (/data/plugins/music_service/spop/index.js:2119:31) Apr 24 10:27:37 volumio volumio[834]: at emitNone (events.js:106:13) Apr 24 10:27:37 volumio volumio[834]: at SpotConnEvents.emit (events.js:208:7) Apr 24 10:27:37 volumio volumio[834]: at SpotConnEvents.parseData (/data/plugins/music_service/spop/SpotConnController.js:89:16) Apr 24 10:27:37 volumio volumio[834]: at Socket.SpotConnEvents._udpsource.on.msg (/data/plugins/music_service/spop/SpotConnController.js:15:12) Apr 24 10:27:37 volumio volumio[834]: at emitTwo (events.js:126:13) Apr 24 10:27:37 volumio volumio[834]: at Socket.emit (events.js:214:7) Apr 24 10:27:37 volumio volumio[834]: at UDP.onMessage [as onmessage] (dgram.js:659:8) Apr 24 10:27:37 volumio volumio[834]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 24 10:27:38 volumio sudo[2751]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-24 10:26 Apr 24 10:27:38 volumio sudo[2751]: 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"