-- Logs begin at Sat 2024-07-06 10:56:00 EEST, end at Sat 2024-07-06 13:10:26 EEST. -- Jul 06 13:09:08 volumio volumio[970]: info: CoreCommandRouter::volumioGetState Jul 06 13:09:18 volumio volumio[970]: info: CoreCommandRouter::volumioGetState Jul 06 13:09:18 volumio volumio[970]: info: Listing playlists Jul 06 13:09:18 volumio volumio[970]: info: Listing playlists Jul 06 13:09:28 volumio volumio[970]: info: CoreCommandRouter::volumioGetState Jul 06 13:09:38 volumio volumio[970]: info: CoreCommandRouter::volumioGetState Jul 06 13:09:38 volumio volumio[970]: info: Listing playlists Jul 06 13:09:38 volumio volumio[970]: info: Listing playlists Jul 06 13:09:48 volumio volumio[970]: info: CoreCommandRouter::volumioGetState Jul 06 13:09:58 volumio volumio[970]: info: CoreCommandRouter::volumioGetState Jul 06 13:09:58 volumio volumio[970]: info: Listing playlists Jul 06 13:09:58 volumio volumio[970]: info: Listing playlists Jul 06 13:10:08 volumio volumio[970]: info: CoreCommandRouter::volumioGetState Jul 06 13:10:18 volumio volumio[970]: info: CoreCommandRouter::volumioGetState Jul 06 13:10:18 volumio volumio[970]: info: Listing playlists Jul 06 13:10:18 volumio volumio[970]: info: Listing playlists Jul 06 13:10:19 volumio volumio[6267]: [Vollibrespot] : Event: SessionActive { became_active_at: 1720260619402 } Jul 06 13:10:19 volumio volumio[6267]: [Vollibrespot] : SessionActive! Jul 06 13:10:19 volumio volumio[6267]: [Vollibrespot] : Fetching autoplay context uri Jul 06 13:10:19 volumio volumio[6267]: [Vollibrespot] : Event: PlaybackStarted { track_id: SpotifyId { id: 300024790167053981471933811155173635568, audio_type: Track } } Jul 06 13:10:19 volumio volumio[6267]: [Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 300024790167053981471933811155173635568, audio_type: Track } } Jul 06 13:10:19 volumio volumio[970]: [SpotifyConnect] A connect session has begun Jul 06 13:10:19 volumio volumio[970]: [SpotifyConnect] Device palyback is active! Jul 06 13:10:19 volumio volumio[970]: [SpotifyConnect] Device palyback is loading Jul 06 13:10:19 volumio volumio[6267]: [Vollibrespot] : Autoplay uri resolved to <"spotify:station:artist:69GGBxA162lTqCwzJG5jLp"> Jul 06 13:10:19 volumio volumio[6267]: [Vollibrespot] : Resolving uri "spotify:station:artist:69GGBxA162lTqCwzJG5jLp" Jul 06 13:10:19 volumio volumio[6267]: [Vollibrespot] : Loading with Spotify URI Jul 06 13:10:19 volumio volumio[6267]: [Vollibrespot] : Event: GotToken { token: Token { access_token: "BQDQGxaYhKdFBKANVwGbJU8am_OzJ3ptj_SN4EyEJTh9wss9G_DEhr63dEn8to8WxSjg4lZqJzLFiRDavtwT5YtItvci_eDemBJ4KXeflcghf37R43sRTv9VIKvmX479htWSOeiHaGtK51OO79-GFhVF16WJVM-NaW01YIEVL1ng43BjUDEOVIcJH30OEd9s4MTtancuGrJ7Y13-EMpPlNEq3OhuKA", expires_in: 3600, token_type: "Bearer", scope: ["streaming", "user-read-playback-state", "user-modify-playback-state", "user-read-currently-playing", "user-read-private"] } } Jul 06 13:10:19 volumio volumio[970]: error: Received malformed Token, ignoring Jul 06 13:10:19 volumio volumio[6267]: [Vollibrespot] : Resolved 50 tracks from <"spotify:artist:69GGBxA162lTqCwzJG5jLp"> Jul 06 13:10:20 volumio volumio[6267]: [Vollibrespot] : (247160 ms) loaded Jul 06 13:10:20 volumio volumio[6267]: [Vollibrespot] : Event: SinkActive Jul 06 13:10:20 volumio volumio[970]: [SpotifyConnect] Sink acquired Jul 06 13:10:20 volumio volumio[970]: info: Continuing Spotify Session Jul 06 13:10:20 volumio volumio[970]: info: Checking Spotify Web API Jul 06 13:10:20 volumio volumio[970]: [SpotifyConnect] Vollibrespot Active Jul 06 13:10:20 volumio volumio[970]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 06 13:10:20 volumio volumio[970]: info: [1720260620276] ControllerSpotify::pushState Jul 06 13:10:20 volumio volumio[970]: info: CoreCommandRouter::servicePushState Jul 06 13:10:20 volumio volumio[970]: info: CoreStateMachine::pushState Jul 06 13:10:20 volumio volumio[970]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 06 13:10:20 volumio volumio[970]: info: CoreCommandRouter::volumioPushState Jul 06 13:10:24 volumio volumio[6267]: [Vollibrespot] : Event: Pause { track_id: SpotifyId { id: 300024790167053981471933811155173635568, audio_type: Track }, position_ms: 6164 } Jul 06 13:10:24 volumio volumio[970]: [SpotifyConnect] pause Jul 06 13:10:25 volumio volumio[970]: [SpotifyConnect] Something Just Like This Jul 06 13:10:25 volumio volumio[6267]: [Vollibrespot] : Event: SinkInactive Jul 06 13:10:25 volumio volumio[6267]: [Vollibrespot] : Event: PlaybackStopped { track_id: SpotifyId { id: 300024790167053981471933811155173635568, audio_type: Track } } Jul 06 13:10:25 volumio volumio[970]: [SpotifyConnect] PlaybackInactive Jul 06 13:10:25 volumio volumio[970]: info: [1720260625238] ControllerSpotify::pushState Jul 06 13:10:25 volumio volumio[970]: info: CoreCommandRouter::servicePushState Jul 06 13:10:25 volumio volumio[970]: info: CoreStateMachine::pushState Jul 06 13:10:25 volumio volumio[970]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 06 13:10:25 volumio volumio[970]: info: CoreCommandRouter::volumioPushState Jul 06 13:10:25 volumio volumio[970]: info: Renewing Access Token via Daemon Jul 06 13:10:25 volumio volumio[970]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 06 13:10:25 volumio volumio[970]: TypeError: self.refreshAccessToken(...).then(...).fail(...).catch is not a function Jul 06 13:10:25 volumio volumio[970]: at ControllerSpotify.spotifyCheckAccessToken (/data/plugins/music_service/spop/index.js:251:17) Jul 06 13:10:25 volumio volumio[970]: at ControllerSpotify.isPlaybackFromConnectDevice (/data/plugins/music_service/spop/index.js:3105:14) Jul 06 13:10:25 volumio volumio[970]: at Timeout._onTimeout (/data/plugins/music_service/spop/index.js:2319:22) Jul 06 13:10:25 volumio volumio[970]: at listOnTimeout (internal/timers.js:554:17) Jul 06 13:10:25 volumio volumio[970]: at processTimers (internal/timers.js:497:7) Jul 06 13:10:25 volumio volumio[970]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 06 13:10:26 volumio sudo[6909]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-06 13:09 Jul 06 13:10:26 volumio sudo[6909]: 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="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="905ee02fb5387537cfa16b84ebd7f14b7640848e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 04 Jul 2024 02:29:26 AM CEST" VOLUMIO_VERSION="3.735" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="c3549df9b4fb845b268fd7accf565d01"