-- Logs begin at Fri 2024-04-05 13:04:57 UTC, end at Wed 2024-04-10 16:31:56 UTC. -- Apr 10 16:31:09 volumiohans vtcs[2138]: [2024-04-10 16:31:09.313] [tisoc] [warning] [QueueManagerImpl.cpp:816] State=IDLE. Not send NotifyQueueChanged. Apr 10 16:31:09 volumiohans vtcs[2138]: [2024-04-10 16:31:09.313] [tisoc] [warning] [PlaybackControllerImpl.cpp:904] Not send NotifyMediaChanged(media_info is null) Apr 10 16:31:09 volumiohans volumio[1116]: info: CoreCommandRouter::servicePushState Apr 10 16:31:09 volumiohans volumio[1116]: info: CoreStateMachine::pushState Apr 10 16:31:09 volumiohans volumio[1116]: info: CoreCommandRouter::volumioPushState Apr 10 16:31:09 volumiohans volumio[1116]: info: MRS: Pushing multiroomSync output update for this device Apr 10 16:31:09 volumiohans volumio[1116]: info: MRS: Pushing multiroomSync output Apr 10 16:31:09 volumiohans volumio[1116]: info: CorePlayQueue::getTrack 0 Apr 10 16:31:09 volumiohans volumio[1116]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received tidalconnect Apr 10 16:31:09 volumiohans volumio[1116]: info: CoreCommandRouter::servicePushState Apr 10 16:31:09 volumiohans volumio[1116]: info: CoreStateMachine::pushState Apr 10 16:31:09 volumiohans volumio[1116]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 10 16:31:09 volumiohans volumio[1116]: info: CoreCommandRouter::volumioPushState Apr 10 16:31:09 volumiohans volumio[1116]: info: MRS: Pushing multiroomSync output update for this device Apr 10 16:31:09 volumiohans volumio[1116]: info: MRS: Pushing multiroomSync output Apr 10 16:31:09 volumiohans volumio[1116]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.rkN4RTz6pbayK7GtJCZwX4K0dwk1.f8bb58a5ddf046ee7e2cd8be5335d395.state.status' Apr 10 16:31:14 volumiohans vtcs[2138]: [2024-04-10 16:31:14.944] [tisoc] [warning] [PlaybackControllerImpl.cpp:501] Illegal state:1 Apr 10 16:31:14 volumiohans volumio[1116]: info: PlaybackInactive Apr 10 16:31:14 volumiohans volumio[1116]: info: Device Session is_active: true Apr 10 16:31:14 volumiohans volumio[1116]: info: DeviceInactive Apr 10 16:31:14 volumiohans volumio[1116]: info: Relinquishing Volumio State Apr 10 16:31:14 volumiohans volumio[1116]: verbose: UNSET VOLATILE: Service: tidalconnect Apr 10 16:31:14 volumiohans volumio[1116]: info: unSetVolatile called Apr 10 16:31:14 volumiohans volumio[1116]: info: Relinquishing Volumio State to another service Apr 10 16:31:14 volumiohans vtcs[2138]: [2024-04-10 16:31:14.947] [tisoc] [warning] [SessionManagerImpl.cpp:243] Illegal State: IDLE Apr 10 16:31:14 volumiohans vtcs[2138]: [2024-04-10 16:31:14] [info] asio async_shutdown error: asio.misc:2 (End of file) Apr 10 16:31:20 volumiohans volumio[1116]: info: CoreCommandRouter::volumioGetState Apr 10 16:31:20 volumiohans volumio[1116]: info: CorePlayQueue::getTrack 0 Apr 10 16:31:20 volumiohans volumio[1116]: info: CoreCommandRouter::volumioGetState Apr 10 16:31:20 volumiohans volumio[1116]: info: CorePlayQueue::getTrack 0 Apr 10 16:31:20 volumiohans volumio[1116]: info: Currently active: webradio Apr 10 16:31:20 volumiohans volumio[1116]: info: Stopping currently active service Apr 10 16:31:20 volumiohans volumio[1116]: info: CoreCommandRouter::volumioStop Apr 10 16:31:20 volumiohans volumio[1116]: info: CoreStateMachine::stop Apr 10 16:31:20 volumiohans volumio[1116]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 10 16:31:20 volumiohans volumio[1116]: info: CoreStateMachine::updateTrackBlock Apr 10 16:31:20 volumiohans volumio[1116]: info: CorePlayQueue::getTrackBlock Apr 10 16:31:20 volumiohans volumio[1116]: info: CoreStateMachine::stPlaybackTimer Apr 10 16:31:20 volumiohans volumio[1116]: info: CoreStateMachine::pushState Apr 10 16:31:20 volumiohans volumio[1116]: info: CorePlayQueue::getTrack 0 Apr 10 16:31:20 volumiohans volumio[1116]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 10 16:31:20 volumiohans volumio[1116]: info: CoreCommandRouter::volumioPushState Apr 10 16:31:20 volumiohans volumio[1116]: info: MRS: Pushing multiroomSync output update for this device Apr 10 16:31:20 volumiohans volumio[1116]: info: MRS: Pushing multiroomSync output Apr 10 16:31:20 volumiohans volumio[1116]: info: CoreStateMachine::serviceStop Apr 10 16:31:20 volumiohans volumio[1116]: info: CorePlayQueue::getTrack 0 Apr 10 16:31:20 volumiohans volumio[1116]: info: CoreCommandRouter::serviceStop Apr 10 16:31:20 volumiohans volumio[1116]: info: [1712766680549] ControllerWebradio::stop Apr 10 16:31:20 volumiohans volumio[1116]: verbose: ControllerMpd::sendMpdCommand stop Apr 10 16:31:20 volumiohans volumio[1116]: info: sendMpdCommand stop took 30 milliseconds Apr 10 16:31:20 volumiohans volumio[1116]: info: TidalConnect Active Apr 10 16:31:20 volumiohans volumio[1116]: info: CoreCommandRouter::volumioGetState Apr 10 16:31:20 volumiohans volumio[1116]: info: CorePlayQueue::getTrack 0 Apr 10 16:31:20 volumiohans volumio[1116]: info: Currently active: webradio Apr 10 16:31:20 volumiohans volumio[1116]: info: Setting Volatile state to tidalconnect Apr 10 16:31:20 volumiohans volumio[1116]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 10 16:31:20 volumiohans volumio[1116]: info: CoreCommandRouter::servicePushState Apr 10 16:31:20 volumiohans volumio[1116]: info: CoreStateMachine::pushState Apr 10 16:31:20 volumiohans volumio[1116]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 10 16:31:20 volumiohans volumio[1116]: info: CoreCommandRouter::volumioPushState Apr 10 16:31:20 volumiohans volumio[1116]: info: MRS: Pushing multiroomSync output update for this device Apr 10 16:31:20 volumiohans volumio[1116]: info: MRS: Pushing multiroomSync output Apr 10 16:31:20 volumiohans volumio[1116]: info: CoreCommandRouter::servicePushState Apr 10 16:31:20 volumiohans volumio[1116]: info: CoreStateMachine::pushState Apr 10 16:31:20 volumiohans volumio[1116]: info: CoreCommandRouter::volumioPushState Apr 10 16:31:20 volumiohans volumio[1116]: info: MRS: Pushing multiroomSync output update for this device Apr 10 16:31:20 volumiohans volumio[1116]: info: MRS: Pushing multiroomSync output Apr 10 16:31:22 volumiohans vtcs[2138]: [2024-04-10 16:31:22.273] [tisoc] [warning] [PlaybackControllerImpl.cpp:202] Illegal state:1 Apr 10 16:31:23 volumiohans vtcs[2138]: [2024-04-10 16:31:23.624] [tisoc] [warning] [PlaybackControllerImpl.cpp:202] Illegal state:1 Apr 10 16:31:23 volumiohans vtcs[2138]: [2024-04-10 16:31:23.863] [tisoc] [warning] [PlaybackControllerImpl.cpp:202] Illegal state:1 Apr 10 16:31:24 volumiohans vtcs[2138]: [2024-04-10 16:31:24.102] [tisoc] [warning] [PlaybackControllerImpl.cpp:202] Illegal state:1 Apr 10 16:31:24 volumiohans vtcs[2138]: [2024-04-10 16:31:24.333] [tisoc] [warning] [PlaybackControllerImpl.cpp:202] Illegal state:1 Apr 10 16:31:25 volumiohans vtcs[2138]: [2024-04-10 16:31:25.183] [tisoc] [warning] [PlaybackControllerImpl.cpp:202] Illegal state:1 Apr 10 16:31:25 volumiohans vtcs[2138]: [2024-04-10 16:31:25.423] [tisoc] [warning] [PlaybackControllerImpl.cpp:202] Illegal state:1 Apr 10 16:31:25 volumiohans vtcs[2138]: [2024-04-10 16:31:25.905] [tisoc] [warning] [PlaybackControllerImpl.cpp:202] Illegal state:1 Apr 10 16:31:28 volumiohans vtcs[2138]: [2024-04-10 16:31:28] [info] asio async_shutdown error: asio.misc:2 (End of file) Apr 10 16:31:55 volumiohans volumio[2065]: [Vollibrespot] : Connecting to AP "ap-gew4.spotify.com:443" Apr 10 16:31:55 volumiohans volumio[2065]: [Vollibrespot] : Authenticated as "3aj9vd8t9i2ncbjbgcf3y7icv" ! Apr 10 16:31:55 volumiohans volumio[2065]: [Vollibrespot] : Setting up new mixer: card:hw:0 mixer:Digital index:0 Apr 10 16:31:55 volumiohans volumio[2065]: [Vollibrespot] : Alsa min-db is not SND_CTL_TLV_DB_GAIN_MUTE!! Apr 10 16:31:55 volumiohans volumio[2065]: [Vollibrespot] : Alsa Mixer info min: 0 (MilliBel(-10000)[dB]) -- max: 100 (MilliBel(0)[dB]) HW: true Apr 10 16:31:55 volumiohans volumio[2065]: [Vollibrespot] : Alsa min-db is not SND_CTL_TLV_DB_GAIN_MUTE!! Apr 10 16:31:55 volumiohans volumio[2065]: [Vollibrespot] : Using alsa sink Apr 10 16:31:55 volumiohans volumio[2065]: [Vollibrespot] : Metadata pipe established Apr 10 16:31:55 volumiohans volumio[2065]: [Vollibrespot] : Country: "NL" Apr 10 16:31:55 volumiohans volumio[2065]: [Vollibrespot] : Event: Volume { volume_to_mixer: 0 } Apr 10 16:31:55 volumiohans volumio[1116]: [SpotifyConnect] 0 Apr 10 16:31:55 volumiohans volumio[1116]: [SpotifyConnect] Volume: Spotify:0 Volumio: 0 Apr 10 16:31:55 volumiohans volumio[1116]: info: CoreCommandRouter::volumioGetState Apr 10 16:31:55 volumiohans volumio[1116]: info: CoreStateMachine::pushState Apr 10 16:31:55 volumiohans volumio[1116]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 10 16:31:55 volumiohans volumio[1116]: info: CoreCommandRouter::volumioPushState Apr 10 16:31:55 volumiohans volumio[1116]: info: MRS: Pushing multiroomSync output update for this device Apr 10 16:31:55 volumiohans volumio[1116]: info: MRS: Pushing multiroomSync output Apr 10 16:31:55 volumiohans volumio[2065]: [Vollibrespot] : Event: SessionActive { became_active_at: 1712766715894 } Apr 10 16:31:55 volumiohans volumio[2065]: [Vollibrespot] : SessionActive! Apr 10 16:31:55 volumiohans volumio[2065]: [Vollibrespot] : Fetching autoplay context uri Apr 10 16:31:55 volumiohans volumio[2065]: [Vollibrespot] : Event: PlaybackStarted { track_id: SpotifyId { id: 320929800980099864982749794765881896851, audio_type: Track } } Apr 10 16:31:55 volumiohans volumio[2065]: [Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 320929800980099864982749794765881896851, audio_type: Track } } Apr 10 16:31:55 volumiohans volumio[1116]: [SpotifyConnect] A connect session has begun Apr 10 16:31:55 volumiohans volumio[1116]: [SpotifyConnect] Device palyback is active! Apr 10 16:31:55 volumiohans volumio[1116]: info: CoreCommandRouter::volumioGetState Apr 10 16:31:55 volumiohans volumio[1116]: [SpotifyConnect] Currently active: tidalconnect Apr 10 16:31:55 volumiohans volumio[1116]: [SpotifyConnect] Stopping currently active service Apr 10 16:31:55 volumiohans volumio[1116]: info: CoreCommandRouter::volumioStop Apr 10 16:31:55 volumiohans volumio[1116]: info: CoreStateMachine::stop Apr 10 16:31:55 volumiohans volumio[1116]: info: CoreStateMachine::serviceStop Apr 10 16:31:55 volumiohans volumio[1116]: info: CoreCommandRouter::serviceStop Apr 10 16:31:55 volumiohans vtcs[2138]: [2024-04-10 16:31:55.907] [tisoc] [warning] [PlaybackControllerImpl.cpp:501] Illegal state:0 Apr 10 16:31:55 volumiohans volumio[1116]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 10 16:31:55 volumiohans volumio[1116]: TypeError: Cannot read property 'then' of undefined Apr 10 16:31:55 volumiohans volumio[1116]: at SpotConnEvents. (/data/plugins/music_service/volspotconnect2/index.js:143:23) Apr 10 16:31:55 volumiohans volumio[1116]: at SpotConnEvents.emit (events.js:400:28) Apr 10 16:31:55 volumiohans volumio[1116]: at SpotConnEvents.parseData (/data/plugins/music_service/volspotconnect2/SpotConnController.js:73:16) Apr 10 16:31:55 volumiohans volumio[1116]: at Socket. (/data/plugins/music_service/volspotconnect2/SpotConnController.js:15:12) Apr 10 16:31:55 volumiohans volumio[1116]: at Socket.emit (events.js:400:28) Apr 10 16:31:55 volumiohans volumio[1116]: at UDP.onMessage [as onmessage] (dgram.js:931:8) Apr 10 16:31:55 volumiohans volumio[1116]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 10 16:31:55 volumiohans volumio[2065]: [Vollibrespot] : Autoplay uri resolved to <"spotify:station:artist:6HEfa1UMc2DCOEMfI3R7rs"> Apr 10 16:31:55 volumiohans volumio[2065]: [Vollibrespot] : Resolving uri "spotify:station:artist:6HEfa1UMc2DCOEMfI3R7rs" Apr 10 16:31:55 volumiohans volumio[2065]: [Vollibrespot] : Event: GotToken { token: Token { access_token: "BQBcn3kFTcKKqabz8OyfvEExHWqFBZmK8On5yEovW30sGGjyvkYnTFFw6bHE8hSUhfutoAoK8fnfYoD5TslvL7gj89XS55sybm0W1_IFVI3GwQOkRnJFtnzFWFzvFmEzlFtih8og69mr9i4DAa7qoHWhP68N9UFKNrJCBRywVIv-qpkSk5U4WWwfTx8IsAJFm7833JJeVTUKW6esMBOBWLGxFQ", expires_in: 3600, token_type: "Bearer", scope: ["streaming", "user-read-playback-state", "user-modify-playback-state", "user-read-currently-playing", "user-read-private"] } } Apr 10 16:31:55 volumiohans volumio[2065]: [Vollibrespot] : Loading with Spotify URI Apr 10 16:31:56 volumiohans volumio[2065]: [Vollibrespot] : Resolved 50 tracks from <"spotify:artist:6HEfa1UMc2DCOEMfI3R7rs"> Apr 10 16:31:56 volumiohans sudo[2418]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-10 16:30 Apr 10 16:31:56 volumiohans sudo[2418]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="e831866afe2db61aee9333a8f5ba9d9fd36609c7" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sun 18 Feb 2024 11:15:21 AM CET" VOLUMIO_VERSION="3.629" VOLUMIO_HARDWARE="tinkerboard" VOLUMIO_DEVICENAME="Asus Tinkerboard" VOLUMIO_HASH="293a767fd1b71cabc5f5be4916f770a0"