-- Logs begin at Sat 2025-05-10 02:51:58 UTC, end at Tue 2025-05-13 11:02:57 UTC. -- May 13 11:02:15 volumio volumio[17162]: info: Tunnel connection is inactive, restarting it May 13 11:02:15 volumio volumio[17162]: info: Starting Tunnel 1 May 13 11:02:15 volumio volumio[17162]: info: Starting Tunnel Connection Checker May 13 11:02:15 volumio sudo[321]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service May 13 11:02:15 volumio sudo[321]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 11:02:15 volumio systemd[1]: Stopping MyVolumio SSH Tunnel... May 13 11:02:15 volumio autossh[32231]: received signal to exit (15) May 13 11:02:15 volumio systemd[1]: Starting MyVolumio SSH Tunnel... May 13 11:02:15 volumio systemd[1]: Started MyVolumio SSH Tunnel. May 13 11:02:15 volumio sudo[321]: pam_unix(sudo:session): session closed for user root May 13 11:02:15 volumio autossh[328]: port set to 0, monitoring disabled May 13 11:02:15 volumio autossh[328]: starting ssh (count 1) May 13 11:02:15 volumio autossh[328]: ssh child pid is 334 May 13 11:02:15 volumio volumio[17162]: ------------------------------------ BT MESSAGE: BT STATUS: running May 13 11:02:15 volumio volumio[17162]: BT PLUGIN MESSAGE: Playing: false May 13 11:02:15 volumio volumio[17162]: BT PLUGIN MESSAGE: VOLATILE: tidalconnect May 13 11:02:15 volumio volumio[17162]: BT PLUGIN MESSAGE: STATE:undefined May 13 11:02:15 volumio volumio[17162]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 13 11:02:15 volumio volumio[17162]: BT PLUGIN MESSAGE: Playing: false May 13 11:02:15 volumio volumio[17162]: BT PLUGIN MESSAGE: VOLATILE: tidalconnect May 13 11:02:15 volumio volumio[17162]: BT PLUGIN MESSAGE: STATE:undefined May 13 11:02:15 volumio volumio[17162]: info: Remote SSH Started May 13 11:02:15 volumio volumio[17162]: info: CoreCommandRouter::volumioGetState May 13 11:02:15 volumio volumiossh-tunnel[327]: Warning: Permanently added '[as1.myvolumio.org]:2222,[128.199.166.162]:2222' (RSA) to the list of known hosts. May 13 11:02:55 volumio volumio[1185]: [Vollibrespot] : Connecting to AP "ap-gae2.spotify.com:443" May 13 11:02:55 volumio volumio[1185]: [Vollibrespot] : Authenticated as "12177287486" ! May 13 11:02:55 volumio volumio[1185]: [Vollibrespot] : Using alsa sink May 13 11:02:55 volumio volumio[1185]: [Vollibrespot] : Metadata pipe established May 13 11:02:55 volumio volumio[1185]: [Vollibrespot] : Event: Volume { volume_to_mixer: 65535 } May 13 11:02:55 volumio volumio[1185]: [Vollibrespot] : Country: "HK" May 13 11:02:55 volumio volumio[17162]: [SpotifyConnect] 100 May 13 11:02:55 volumio volumio[17162]: [SpotifyConnect] Volume: Spotify:100 Volumio: 100 May 13 11:02:55 volumio volumio[17162]: info: CoreStateMachine::pushState May 13 11:02:55 volumio volumio[17162]: info: CoreCommandRouter::volumioPushState May 13 11:02:55 volumio volumio[17162]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 11:02:56 volumio volumio[1185]: [Vollibrespot] : Event: SessionActive { became_active_at: 1747134176303 } May 13 11:02:56 volumio volumio[1185]: [Vollibrespot] : SessionActive! May 13 11:02:56 volumio volumio[1185]: [Vollibrespot] : Fetching autoplay context uri May 13 11:02:56 volumio volumio[1185]: [Vollibrespot] : Event: PlaybackStarted { track_id: SpotifyId { id: 186796667937695242518120704690915366495, audio_type: Track } } May 13 11:02:56 volumio volumio[1185]: [Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 186796667937695242518120704690915366495, audio_type: Track } } May 13 11:02:56 volumio volumio[1185]: [Vollibrespot] : Loading <迷失藝術> with Spotify URI May 13 11:02:56 volumio volumio[1185]: [Vollibrespot] : Autoplay uri resolved to <"spotify:station:artist:27WDr8Ky1j0LtgY82Ttk5S"> May 13 11:02:56 volumio volumio[1185]: [Vollibrespot] : Resolving uri "spotify:station:artist:27WDr8Ky1j0LtgY82Ttk5S" May 13 11:02:56 volumio volumio[1185]: [Vollibrespot] : Event: GotToken { token: Token { access_token: "BQClE2t91cOzICpuyUxZWnjemXAQ8oiJQs0dZf-ZWsvsvFfhmwsvPWpuqDqqEkor8l7q7XHcNGxr2eDKuoQT7cZLo-bOGj0aCv8ozidlpueut3GUJSJMzAIpqWpr3gqbEwLbviAVMn9a8sfqL5BhrPhJYBxAKcTwsGDREQ13WXPsbfBnlXcba7Q_pSmAkyZ_FiN0oA78Ef2bGaBkLEGliG_Q_-o2dNbMTxWpvkZo-xt0Mns", expires_in: 3600, token_type: "Bearer", scope: ["streaming", "user-read-playback-state", "user-modify-playback-state", "user-read-currently-playing", "user-read-private"] } } May 13 11:02:56 volumio volumio[1185]: [Vollibrespot] : Resolved 50 tracks from <"spotify:artist:27WDr8Ky1j0LtgY82Ttk5S"> May 13 11:02:56 volumio volumio[17162]: [SpotifyConnect] A connect session has begun May 13 11:02:56 volumio volumio[17162]: [SpotifyConnect] Device palyback is active! May 13 11:02:56 volumio volumio[17162]: info: CoreCommandRouter::volumioGetState May 13 11:02:56 volumio volumio[17162]: [SpotifyConnect] Currently active: tidalconnect May 13 11:02:56 volumio volumio[17162]: [SpotifyConnect] Stopping currently active service May 13 11:02:56 volumio volumio[17162]: info: CoreCommandRouter::volumioStop May 13 11:02:56 volumio volumio[17162]: info: CoreStateMachine::stop May 13 11:02:56 volumio volumio[17162]: info: CoreStateMachine::serviceStop May 13 11:02:56 volumio volumio[17162]: info: CoreCommandRouter::serviceStop May 13 11:02:56 volumio volumio[17162]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 13 11:02:56 volumio volumio[17162]: TypeError: Cannot read property 'then' of undefined May 13 11:02:56 volumio volumio[17162]: at SpotConnEvents.SpotConn.on (/data/plugins/music_service/volspotconnect2/index.js:143:23) May 13 11:02:56 volumio volumio[17162]: at emitNone (events.js:106:13) May 13 11:02:56 volumio volumio[17162]: at SpotConnEvents.emit (events.js:208:7) May 13 11:02:56 volumio volumio[17162]: at SpotConnEvents.parseData (/data/plugins/music_service/volspotconnect2/SpotConnController.js:73:16) May 13 11:02:56 volumio volumio[17162]: at Socket.SpotConnEvents._udpsource.on.msg (/data/plugins/music_service/volspotconnect2/SpotConnController.js:15:12) May 13 11:02:56 volumio volumio[17162]: at emitTwo (events.js:126:13) May 13 11:02:56 volumio volumio[17162]: at Socket.emit (events.js:214:7) May 13 11:02:56 volumio volumio[17162]: at UDP.onMessage [as onmessage] (dgram.js:659:8) May 13 11:02:56 volumio volumio[17162]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 13 11:02:56 volumio vtcs[17490]: [2025-05-13 11:02:56] [info] asio async_shutdown error: asio.misc:2 (End of file) May 13 11:02:57 volumio volumio[1185]: [Vollibrespot] : <迷失藝術> (242586 ms) loaded May 13 11:02:57 volumio volumio[1185]: [Vollibrespot] : Event: SinkActive May 13 11:02:57 volumio kernel: bcm2835-i2s 3f203000.i2s: I2S SYNC error! May 13 11:02:57 volumio sudo[453]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-13 11:01 May 13 11:02:57 volumio sudo[453]: 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"