-- Logs begin at Thu 2019-02-14 10:11:59 UTC, end at Thu 2024-10-31 01:43:11 UTC. -- Oct 31 01:42:12 volumio volumio[649]: info: CoreCommandRouter::servicePushState Oct 31 01:42:12 volumio volumio[649]: info: CoreStateMachine::pushState Oct 31 01:42:12 volumio volumio[649]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 01:42:12 volumio volumio[649]: info: CoreCommandRouter::volumioPushState Oct 31 01:42:24 volumio volumio[649]: info: CoreCommandRouter::servicePushState Oct 31 01:42:24 volumio volumio[649]: info: CoreStateMachine::pushState Oct 31 01:42:24 volumio volumio[649]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 01:42:24 volumio volumio[649]: info: CoreCommandRouter::volumioPushState Oct 31 01:42:24 volumio volumio[649]: info: Pushing metadata Oct 31 01:42:24 volumio volumio[649]: info: CoreCommandRouter::servicePushState Oct 31 01:42:24 volumio volumio[649]: info: CoreStateMachine::pushState Oct 31 01:42:24 volumio volumio[649]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 01:42:24 volumio volumio[649]: info: CoreCommandRouter::volumioPushState Oct 31 01:42:24 volumio volumio[649]: info: CoreCommandRouter::servicePushState Oct 31 01:42:24 volumio volumio[649]: info: CoreStateMachine::pushState Oct 31 01:42:24 volumio volumio[649]: info: CoreCommandRouter::volumioPushState Oct 31 01:42:24 volumio volumio[649]: info: CoreCommandRouter::servicePushState Oct 31 01:42:24 volumio volumio[649]: info: CoreStateMachine::pushState Oct 31 01:42:24 volumio volumio[649]: info: CoreCommandRouter::volumioPushState Oct 31 01:42:24 volumio volumio[649]: info: CoreCommandRouter::servicePushState Oct 31 01:42:24 volumio volumio[649]: info: CoreStateMachine::pushState Oct 31 01:42:24 volumio volumio[649]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 01:42:24 volumio volumio[649]: info: CoreCommandRouter::volumioPushState Oct 31 01:42:25 volumio volumio[649]: info: Pushing metadata Oct 31 01:42:25 volumio volumio[649]: info: CoreCommandRouter::servicePushState Oct 31 01:42:25 volumio volumio[649]: info: CoreStateMachine::pushState Oct 31 01:42:25 volumio volumio[649]: info: CoreCommandRouter::volumioPushState Oct 31 01:42:25 volumio volumio[649]: info: CoreCommandRouter::servicePushState Oct 31 01:42:25 volumio volumio[649]: info: CoreStateMachine::pushState Oct 31 01:42:25 volumio volumio[649]: info: CoreCommandRouter::volumioPushState Oct 31 01:42:25 volumio volumio[649]: info: CoreCommandRouter::servicePushState Oct 31 01:42:25 volumio volumio[649]: info: CoreStateMachine::pushState Oct 31 01:42:25 volumio volumio[649]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 01:42:25 volumio volumio[649]: info: CoreCommandRouter::volumioPushState Oct 31 01:42:25 volumio volumio[649]: info: CoreCommandRouter::servicePushState Oct 31 01:42:25 volumio volumio[649]: info: CoreStateMachine::pushState Oct 31 01:42:25 volumio volumio[649]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 01:42:25 volumio volumio[649]: info: CoreCommandRouter::volumioPushState Oct 31 01:42:25 volumio volumio[649]: info: CoreCommandRouter::servicePushState Oct 31 01:42:25 volumio volumio[649]: info: CoreStateMachine::pushState Oct 31 01:42:25 volumio volumio[649]: info: CoreCommandRouter::volumioPushState Oct 31 01:42:25 volumio volumio[649]: info: CoreCommandRouter::servicePushState Oct 31 01:42:25 volumio volumio[649]: info: CoreStateMachine::pushState Oct 31 01:42:25 volumio volumio[649]: info: CoreCommandRouter::volumioPushState Oct 31 01:42:25 volumio vtcs[7781]: [2024-10-31 01:42:25.313] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed: Stream error in the HTTP/2 framing layer - HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2) Oct 31 01:42:25 volumio vtcs[7781]: [2024-10-31 01:42:25.314] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response! Oct 31 01:42:25 volumio vtcs[7781]: [2024-10-31 01:42:25.595] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed: Stream error in the HTTP/2 framing layer - HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2) Oct 31 01:42:25 volumio vtcs[7781]: [2024-10-31 01:42:25.596] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response! Oct 31 01:42:25 volumio vtcs[7781]: [2024-10-31 01:42:25.942] [tisoc] [error] [logger.cpp:25] [operation_curl.cpp:257] curl_easy_perform failed: Stream error in the HTTP/2 framing layer - HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2) Oct 31 01:42:25 volumio vtcs[7781]: [2024-10-31 01:42:25.943] [tisoc] [error] [logger.cpp:25] [http_stream_fetcher.cpp:162] Content-Range is missing from response! Oct 31 01:42:25 volumio vtcs[7781]: [2024-10-31 01:42:25.943] [tisoc] [warning] [logger.cpp:22] [audio_worker.cpp:293] Max connection attempts reached! Oct 31 01:42:25 volumio volumio[649]: info: Unknown command: notifyPlaybackError Oct 31 01:42:25 volumio volumio[649]: info: CoreCommandRouter::servicePushState Oct 31 01:42:25 volumio volumio[649]: info: CoreStateMachine::pushState Oct 31 01:42:25 volumio volumio[649]: info: CoreCommandRouter::volumioPushState Oct 31 01:42:25 volumio volumio[649]: info: CoreCommandRouter::servicePushState Oct 31 01:42:25 volumio volumio[649]: info: CoreStateMachine::pushState Oct 31 01:42:25 volumio volumio[649]: info: CoreCommandRouter::volumioPushState Oct 31 01:43:10 volumio volumio[5301]: [Vollibrespot] : Connecting to AP "ap-gue1.spotify.com:443" Oct 31 01:43:10 volumio volumio[5301]: [Vollibrespot] : Authenticated as "21lhaqpcfndj3a7bhfakqfwpa" ! Oct 31 01:43:10 volumio volumio[5301]: [Vollibrespot] : Using alsa sink Oct 31 01:43:10 volumio volumio[5301]: [Vollibrespot] : Metadata pipe established Oct 31 01:43:10 volumio volumio[5301]: [Vollibrespot] : Country: "US" Oct 31 01:43:10 volumio volumio[5301]: [Vollibrespot] : Event: Volume { volume_to_mixer: 65535 } Oct 31 01:43:10 volumio volumio[649]: [SpotifyConnect] 100 Oct 31 01:43:10 volumio volumio[649]: [SpotifyConnect] Volume: Spotify:100 Volumio: 100 Oct 31 01:43:10 volumio volumio[649]: info: CoreStateMachine::pushState Oct 31 01:43:10 volumio volumio[649]: info: CoreCommandRouter::volumioPushState Oct 31 01:43:10 volumio volumio[5301]: [Vollibrespot] : Fetching autoplay context uri Oct 31 01:43:10 volumio volumio[5301]: [Vollibrespot] : Event: SessionActive { became_active_at: 1730338990787 } Oct 31 01:43:10 volumio volumio[5301]: [Vollibrespot] : SessionActive! Oct 31 01:43:10 volumio volumio[5301]: [Vollibrespot] : Event: PlaybackStarted { track_id: SpotifyId { id: 24034191709905229382379702713380590832, audio_type: Track } } Oct 31 01:43:10 volumio volumio[5301]: [Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 24034191709905229382379702713380590832, audio_type: Track } } Oct 31 01:43:10 volumio volumio[649]: [SpotifyConnect] A connect session has begun Oct 31 01:43:10 volumio volumio[649]: [SpotifyConnect] Device palyback is active! Oct 31 01:43:10 volumio volumio[649]: info: CoreCommandRouter::volumioGetState Oct 31 01:43:10 volumio volumio[649]: [SpotifyConnect] Currently active: tidalconnect Oct 31 01:43:10 volumio volumio[649]: [SpotifyConnect] Stopping currently active service Oct 31 01:43:10 volumio volumio[649]: info: CoreCommandRouter::volumioStop Oct 31 01:43:10 volumio volumio[649]: info: CoreStateMachine::stop Oct 31 01:43:10 volumio volumio[649]: info: CoreStateMachine::serviceStop Oct 31 01:43:10 volumio volumio[649]: info: CoreCommandRouter::serviceStop Oct 31 01:43:10 volumio volumio[649]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 31 01:43:10 volumio vtcs[7781]: [2024-10-31 01:43:10.796] [tisoc] [warning] [PlaybackControllerImpl.cpp:472] Illegal state:0 Oct 31 01:43:10 volumio volumio[649]: TypeError: Cannot read property 'then' of undefined Oct 31 01:43:10 volumio volumio[649]: at SpotConnEvents. (/data/plugins/music_service/volspotconnect2/index.js:143:23) Oct 31 01:43:10 volumio volumio[649]: at SpotConnEvents.emit (events.js:315:20) Oct 31 01:43:10 volumio volumio[649]: at SpotConnEvents.parseData (/data/plugins/music_service/volspotconnect2/SpotConnController.js:73:16) Oct 31 01:43:10 volumio volumio[649]: at Socket. (/data/plugins/music_service/volspotconnect2/SpotConnController.js:15:12) Oct 31 01:43:10 volumio volumio[649]: at Socket.emit (events.js:315:20) Oct 31 01:43:10 volumio volumio[649]: at UDP.onMessage [as onmessage] (dgram.js:919:8) Oct 31 01:43:10 volumio volumio[649]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 31 01:43:10 volumio vtcs[7781]: [2024-10-31 01:43:10] [info] asio async_shutdown error: asio.misc:2 (End of file) Oct 31 01:43:10 volumio volumio[5301]: [Vollibrespot] : Autoplay uri resolved to <"spotify:station:artist:6OWapcJm9xd55ci9CYbAuT"> Oct 31 01:43:10 volumio volumio[5301]: [Vollibrespot] : Resolving uri "spotify:station:artist:6OWapcJm9xd55ci9CYbAuT" Oct 31 01:43:10 volumio volumio[5301]: [Vollibrespot] : Event: GotToken { token: Token { access_token: "BQDLRIgAhYoUKfQOIVi2K0RkkNLtiB0nETTG1NQPe3UJbse5s7Kc4wUghlNo5meBYJ0lyiCq9HImn-e5-5bAZEk211FKbCmi5g-7SJjM8JbHqm8fYOPuRT9g3gPwGj7IfRKbh_AoL5zAwWjkH7VTKjTSuMS95hcZVjq9wqCZp6cqcFi7XuAJwAI_8oJGqy6p8ngrHdkmbZFdl4PYTZFU3yS4WnNHmViCoA", expires_in: 3600, token_type: "Bearer", scope: ["streaming", "user-read-playback-state", "user-modify-playback-state", "user-read-currently-playing", "user-read-private"] } } Oct 31 01:43:10 volumio volumio[5301]: [Vollibrespot] : Loading with Spotify URI Oct 31 01:43:11 volumio volumio[5301]: [Vollibrespot] : Resolved 50 tracks from <"spotify:artist:6OWapcJm9xd55ci9CYbAuT"> Oct 31 01:43:11 volumio sudo[12107]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-31 01:42 Oct 31 01:43:11 volumio sudo[12107]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="543f2de901f774399af6eae9d76f06fe4162e5dd" VOLUMIO_FE_VERSION="175efecbf4f79404c553a8a73d0a8929ba9e68ab" VOLUMIO_FE3_VERSION="9cf29de04cd974cb1504bd8ef33d64f591b09aef" VOLUMIO_BE_VERSION="0bba7bb5721ae1c828390745b52735c56d7c014a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 13 Dec 2021 03:52:13 PM CET" VOLUMIO_VERSION="3.175" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="c1271baa6039839be7f5b1630f3422f4"