-- Logs begin at Sun 2024-08-18 07:06:49 UTC, end at Wed 2024-08-21 19:06:03 UTC. -- Aug 21 19:05:23 volumio volumio[3337]: info: Tunnel connection is inactive, restarting it Aug 21 19:05:23 volumio volumio[3337]: info: Starting Tunnel 1 Aug 21 19:05:23 volumio volumio[3337]: info: Starting Tunnel Connection Checker Aug 21 19:05:23 volumio sudo[22970]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Aug 21 19:05:23 volumio sudo[22970]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 21 19:05:23 volumio systemd[1]: Stopping MyVolumio SSH Tunnel... Aug 21 19:05:23 volumio autossh[22480]: received signal to exit (15) Aug 21 19:05:23 volumio volumio[3337]: ------------------------------------ BT MESSAGE: BT STATUS: running Aug 21 19:05:23 volumio volumio[3337]: BT PLUGIN MESSAGE: Playing: false Aug 21 19:05:23 volumio volumio[3337]: BT PLUGIN MESSAGE: VOLATILE: tidalconnect Aug 21 19:05:23 volumio volumio[3337]: BT PLUGIN MESSAGE: STATE:undefined Aug 21 19:05:23 volumio volumio[3337]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Aug 21 19:05:23 volumio volumio[3337]: BT PLUGIN MESSAGE: Playing: false Aug 21 19:05:23 volumio volumio[3337]: BT PLUGIN MESSAGE: VOLATILE: tidalconnect Aug 21 19:05:23 volumio volumio[3337]: BT PLUGIN MESSAGE: STATE:undefined Aug 21 19:05:23 volumio systemd[1]: Starting MyVolumio SSH Tunnel... Aug 21 19:05:23 volumio systemd[1]: Started MyVolumio SSH Tunnel. Aug 21 19:05:23 volumio sudo[22970]: pam_unix(sudo:session): session closed for user root Aug 21 19:05:23 volumio autossh[22978]: port set to 0, monitoring disabled Aug 21 19:05:23 volumio autossh[22978]: starting ssh (count 1) Aug 21 19:05:23 volumio autossh[22978]: ssh child pid is 22984 Aug 21 19:05:23 volumio volumio[3337]: info: Remote SSH Started Aug 21 19:05:23 volumio volumio[3337]: info: CoreCommandRouter::volumioGetState Aug 21 19:05:23 volumio volumiossh-tunnel[22976]: Warning: Permanently added '[eu6.myvolumio.org]:2222,[207.154.233.230]:2222' (RSA) to the list of known hosts. Aug 21 19:06:01 volumio volumio[1219]: [Vollibrespot] : Connecting to AP "ap-gew4.spotify.com:443" Aug 21 19:06:01 volumio volumio[1219]: [Vollibrespot] : Authenticated as "2v1nl9ogkn359drrtcm3xi5h0" ! Aug 21 19:06:01 volumio volumio[1219]: [Vollibrespot] : Setting up new mixer: card:hw:2 mixer:DAC index:0 Aug 21 19:06:01 volumio volumio[1219]: [Vollibrespot] : Alsa Mixer info min: 0 (MilliBel(-9999999)[dB]) -- max: 240 (MilliBel(0)[dB]) HW: true Aug 21 19:06:01 volumio volumio[1219]: [Vollibrespot] : Using alsa sink Aug 21 19:06:01 volumio volumio[1219]: [Vollibrespot] : Metadata pipe established Aug 21 19:06:01 volumio volumio[1219]: [Vollibrespot] : Country: "DE" Aug 21 19:06:01 volumio volumio[1219]: [Vollibrespot] : Event: Volume { volume_to_mixer: 0 } Aug 21 19:06:01 volumio volumio[3337]: [SpotifyConnect] 0 Aug 21 19:06:01 volumio volumio[3337]: [SpotifyConnect] Volume: Spotify:0 Volumio: 0 Aug 21 19:06:01 volumio volumio[3337]: info: CoreStateMachine::pushState Aug 21 19:06:01 volumio volumio[3337]: info: CoreCommandRouter::volumioPushState Aug 21 19:06:01 volumio volumio[3337]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 21 19:06:02 volumio volumio[1219]: [Vollibrespot] : Fetching autoplay context uri Aug 21 19:06:02 volumio volumio[1219]: [Vollibrespot] : Event: SessionActive { became_active_at: 1724267162195 } Aug 21 19:06:02 volumio volumio[1219]: [Vollibrespot] : SessionActive! Aug 21 19:06:02 volumio volumio[1219]: [Vollibrespot] : Event: PlaybackStarted { track_id: SpotifyId { id: 163758903121558006619562492970984501580, audio_type: Track } } Aug 21 19:06:02 volumio volumio[1219]: [Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 163758903121558006619562492970984501580, audio_type: Track } } Aug 21 19:06:02 volumio volumio[1219]: [Vollibrespot] : Autoplay uri resolved to <"spotify:station:playlist:3TFGFggdEjjsqJBM8ntsjT"> Aug 21 19:06:02 volumio volumio[1219]: [Vollibrespot] : Resolving uri "spotify:station:playlist:3TFGFggdEjjsqJBM8ntsjT" Aug 21 19:06:02 volumio volumio[1219]: [Vollibrespot] : Event: GotToken { token: Token { access_token: "BQDQJdlMuhlIVdUvLyFwSfD9k18sq8oBWs6XzJbwLTRU7nJIFjtDQB__NsLdh7rkdvPiat0qs8BsSPYNuTXaHuyrgNwSiAm_yqys52O32QJamXzTexjBIh6rHs9WUmWZGtT1wTfj7mI0N0hOuYQPH21K8F8E7584P2F0z8tQpy1t4jNUCKTbAGiRYulS9rGroftwTQi31UEMpdFyEcLyCUbnFtuJkAdEOA", expires_in: 3600, token_type: "Bearer", scope: ["streaming", "user-read-playback-state", "user-modify-playback-state", "user-read-currently-playing", "user-read-private"] } } Aug 21 19:06:02 volumio volumio[1219]: [Vollibrespot] : Loading with Spotify URI Aug 21 19:06:02 volumio volumio[3337]: [SpotifyConnect] A connect session has begun Aug 21 19:06:02 volumio volumio[3337]: [SpotifyConnect] Device palyback is active! Aug 21 19:06:02 volumio volumio[1219]: [Vollibrespot] : Resolved 50 tracks from <"spotify:playlist:3TFGFggdEjjsqJBM8ntsjT"> Aug 21 19:06:02 volumio volumio[3337]: info: CoreCommandRouter::volumioGetState Aug 21 19:06:02 volumio volumio[3337]: [SpotifyConnect] Currently active: tidalconnect Aug 21 19:06:02 volumio volumio[3337]: [SpotifyConnect] Stopping currently active service Aug 21 19:06:02 volumio volumio[3337]: info: CoreCommandRouter::volumioStop Aug 21 19:06:02 volumio volumio[3337]: info: CoreStateMachine::stop Aug 21 19:06:02 volumio volumio[3337]: info: CoreStateMachine::serviceStop Aug 21 19:06:02 volumio volumio[3337]: info: CoreCommandRouter::serviceStop Aug 21 19:06:02 volumio volumio[3337]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 21 19:06:02 volumio volumio[3337]: TypeError: Cannot read property 'then' of undefined Aug 21 19:06:02 volumio volumio[3337]: at SpotConnEvents.SpotConn.on (/data/plugins/music_service/volspotconnect2/index.js:143:23) Aug 21 19:06:02 volumio volumio[3337]: at emitNone (events.js:106:13) Aug 21 19:06:02 volumio volumio[3337]: at SpotConnEvents.emit (events.js:208:7) Aug 21 19:06:02 volumio volumio[3337]: at SpotConnEvents.parseData (/data/plugins/music_service/volspotconnect2/SpotConnController.js:73:16) Aug 21 19:06:02 volumio volumio[3337]: at Socket.SpotConnEvents._udpsource.on.msg (/data/plugins/music_service/volspotconnect2/SpotConnController.js:15:12) Aug 21 19:06:02 volumio volumio[3337]: at emitTwo (events.js:126:13) Aug 21 19:06:02 volumio volumio[3337]: at Socket.emit (events.js:214:7) Aug 21 19:06:02 volumio volumio[3337]: at UDP.onMessage [as onmessage] (dgram.js:659:8) Aug 21 19:06:02 volumio volumio[3337]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 21 19:06:02 volumio vtcs[3757]: [2024-08-21 19:06:02.570] [tisoc] [warning] [PlaybackControllerImpl.cpp:472] Illegal state:0 Aug 21 19:06:02 volumio volumio[1219]: [Vollibrespot] : (245425 ms) loaded Aug 21 19:06:02 volumio volumio[1219]: [Vollibrespot] : Event: SinkActive Aug 21 19:06:02 volumio volumio[1219]: [Vollibrespot] : Event: Volume { volume_to_mixer: 1024 } Aug 21 19:06:03 volumio sudo[23113]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-08-21 19:05 Aug 21 19:06:03 volumio sudo[23113]: 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="dd2a4339faaeb892c7f467e7dc8d424aefb0bd03" VOLUMIO_FE_VERSION="958dedc0edff114f244fa9acc70cf53089d9e5ae" VOLUMIO_BE_VERSION="fd3e37ffec12db034ec93f94dbc26e5495d5b91a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed Oct 6 12:34:49 CEST 2021" VOLUMIO_VERSION="2.917" VOLUMIO_HARDWARE="pi" VOLUMIO_HASH="98c8f08c531a6f0456f17ab17795e35f"