-- Logs begin at Sat 2024-03-30 03:27:06 UTC, end at Tue 2024-04-02 03:54:53 UTC. -- Apr 02 03:53:07 mboss-2 volumio[1232]: info: CoreCommandRouter::volumioGetState Apr 02 03:53:07 mboss-2 volumio[1232]: info: CoreCommandRouter::volumioGetState Apr 02 03:53:07 mboss-2 volumio[1232]: info: Currently active: qobuz Apr 02 03:53:07 mboss-2 volumio[1232]: info: Stopping currently active service Apr 02 03:53:07 mboss-2 volumio[1232]: info: CoreCommandRouter::volumioStop Apr 02 03:53:07 mboss-2 volumio[1232]: info: CoreStateMachine::stop Apr 02 03:53:07 mboss-2 volumio[1232]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 02 03:53:07 mboss-2 volumio[1232]: UNSET VOLATILE Apr 02 03:53:07 mboss-2 volumio[1232]: info: CoreStateMachine::stPlaybackTimer Apr 02 03:53:07 mboss-2 volumio[1232]: info: CoreStateMachine::updateTrackBlock Apr 02 03:53:07 mboss-2 volumio[1232]: info: CorePlayQueue::getTrackBlock Apr 02 03:53:07 mboss-2 volumio[1232]: info: CoreStateMachine::pushState Apr 02 03:53:07 mboss-2 volumio[1232]: info: CorePlayQueue::getTrack 2 Apr 02 03:53:07 mboss-2 volumio[1232]: info: CoreCommandRouter::volumioPushState Apr 02 03:53:07 mboss-2 volumio[1232]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 02 03:53:07 mboss-2 volumio[1232]: info: CoreStateMachine::serviceStop Apr 02 03:53:07 mboss-2 volumio[1232]: info: CorePlayQueue::getTrack 2 Apr 02 03:53:07 mboss-2 volumio[1232]: info: CoreCommandRouter::serviceStop Apr 02 03:53:07 mboss-2 volumio[1232]: info: [1712029987378] ControllerQobuz::stop Apr 02 03:53:07 mboss-2 volumio[1232]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 02 03:53:07 mboss-2 volumio[1232]: info: ControllerMpd::stop Apr 02 03:53:07 mboss-2 volumio[1232]: verbose: ControllerMpd::sendMpdCommand stop Apr 02 03:53:07 mboss-2 volumio[1232]: info: Apr 02 03:53:07 mboss-2 volumio[1232]: ---------------------------- MPD announces state update: player Apr 02 03:53:07 mboss-2 volumio[1232]: info: sendMpdCommand stop took 81 milliseconds Apr 02 03:53:07 mboss-2 volumio[1232]: info: ControllerMpd::getState Apr 02 03:53:07 mboss-2 volumio[1232]: verbose: ControllerMpd::sendMpdCommand status Apr 02 03:53:07 mboss-2 volumio[1232]: info: TidalConnect Active Apr 02 03:53:07 mboss-2 volumio[1232]: info: CoreCommandRouter::volumioGetState Apr 02 03:53:07 mboss-2 volumio[1232]: info: Currently active: mpd Apr 02 03:53:07 mboss-2 volumio[1232]: info: Setting Volatile state to tidalconnect Apr 02 03:53:07 mboss-2 volumio[1232]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 02 03:53:07 mboss-2 volumio[1232]: info: CoreCommandRouter::servicePushState Apr 02 03:53:07 mboss-2 volumio[1232]: info: CoreStateMachine::pushState Apr 02 03:53:07 mboss-2 volumio[1232]: info: CoreCommandRouter::volumioPushState Apr 02 03:53:07 mboss-2 volumio[1232]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 02 03:53:07 mboss-2 volumio[1232]: info: CoreCommandRouter::servicePushState Apr 02 03:53:07 mboss-2 volumio[1232]: info: CoreStateMachine::pushState Apr 02 03:53:07 mboss-2 volumio[1232]: info: CoreCommandRouter::volumioPushState Apr 02 03:53:07 mboss-2 volumio[1232]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 02 03:53:07 mboss-2 volumio[1232]: info: sendMpdCommand status took 26 milliseconds Apr 02 03:53:07 mboss-2 volumio[1232]: verbose: ControllerMpd::parseState Apr 02 03:53:07 mboss-2 volumio[1232]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 02 03:53:07 mboss-2 volumio[1232]: info: sendMpdCommand playlistinfo took 115 milliseconds Apr 02 03:53:07 mboss-2 volumio[1232]: verbose: ControllerMpd::parseTrackInfo Apr 02 03:53:07 mboss-2 volumio[1232]: info: ControllerMpd::pushState Apr 02 03:53:07 mboss-2 volumio[1232]: info: CoreCommandRouter::servicePushState Apr 02 03:53:07 mboss-2 volumio[1232]: info: CoreStateMachine::pushState Apr 02 03:53:07 mboss-2 volumio[1232]: info: CoreCommandRouter::volumioPushState Apr 02 03:53:07 mboss-2 volumio[1232]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 02 03:53:07 mboss-2 volumio[1232]: info: CorePlayQueue::getTrack 2 Apr 02 03:53:07 mboss-2 volumio[1232]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Apr 02 03:53:07 mboss-2 volumio[1232]: info: ------------------------------ 156ms Apr 02 03:53:08 mboss-2 volumio[1232]: info: Pushing metadata Apr 02 03:53:08 mboss-2 volumio[1232]: info: CoreCommandRouter::servicePushState Apr 02 03:53:08 mboss-2 volumio[1232]: info: CoreStateMachine::pushState Apr 02 03:53:08 mboss-2 volumio[1232]: info: CoreCommandRouter::volumioPushState Apr 02 03:53:08 mboss-2 volumio[1232]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 02 03:53:08 mboss-2 volumio[1232]: info: CoreCommandRouter::servicePushState Apr 02 03:53:08 mboss-2 volumio[1232]: info: CoreStateMachine::pushState Apr 02 03:53:08 mboss-2 volumio[1232]: info: CoreCommandRouter::volumioPushState Apr 02 03:53:08 mboss-2 volumio[1232]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 02 03:53:08 mboss-2 volumio[1232]: info: CoreCommandRouter::servicePushState Apr 02 03:53:08 mboss-2 volumio[1232]: info: CoreStateMachine::pushState Apr 02 03:53:08 mboss-2 volumio[1232]: info: CoreCommandRouter::volumioPushState Apr 02 03:53:08 mboss-2 volumio[1232]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 02 03:53:08 mboss-2 volumio[1232]: info: CoreCommandRouter::servicePushState Apr 02 03:53:08 mboss-2 volumio[1232]: info: CoreStateMachine::pushState Apr 02 03:53:08 mboss-2 volumio[1232]: info: CoreCommandRouter::volumioPushState Apr 02 03:53:08 mboss-2 volumio[1232]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 02 03:53:10 mboss-2 volumio[1232]: info: Pushing metadata Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::servicePushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreStateMachine::pushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::volumioPushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::servicePushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreStateMachine::pushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::volumioPushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::servicePushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreStateMachine::pushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::volumioPushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::servicePushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreStateMachine::pushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::volumioPushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::servicePushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreStateMachine::pushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::volumioPushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::servicePushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreStateMachine::pushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::volumioPushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::servicePushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreStateMachine::pushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::volumioPushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::servicePushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreStateMachine::pushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::volumioPushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::servicePushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreStateMachine::pushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::volumioPushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::servicePushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreStateMachine::pushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::volumioPushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::servicePushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreStateMachine::pushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::volumioPushState Apr 02 03:53:10 mboss-2 volumio[1232]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 02 03:53:11 mboss-2 volumio[1232]: info: CoreCommandRouter::servicePushState Apr 02 03:53:11 mboss-2 volumio[1232]: info: CoreStateMachine::pushState Apr 02 03:53:11 mboss-2 volumio[1232]: info: CoreCommandRouter::volumioPushState Apr 02 03:53:11 mboss-2 volumio[1232]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 02 03:53:48 mboss-2 volumio[1232]: info: Tunnel connection is inactive, restarting it Apr 02 03:53:48 mboss-2 volumio[1232]: info: Starting Tunnel 1 Apr 02 03:53:48 mboss-2 volumio[1232]: info: Starting Tunnel Connection Checker Apr 02 03:53:48 mboss-2 sudo[8882]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Apr 02 03:53:48 mboss-2 sudo[8882]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 02 03:53:48 mboss-2 systemd[1]: Stopping MyVolumio SSH Tunnel... Apr 02 03:53:48 mboss-2 autossh[8074]: received signal to exit (15) Apr 02 03:53:48 mboss-2 systemd[1]: Starting MyVolumio SSH Tunnel... Apr 02 03:53:48 mboss-2 systemd[1]: Started MyVolumio SSH Tunnel. Apr 02 03:53:48 mboss-2 volumio[1232]: ------------------------------------ BT MESSAGE: BT STATUS: running Apr 02 03:53:48 mboss-2 volumio[1232]: BT PLUGIN MESSAGE: Playing: false Apr 02 03:53:48 mboss-2 volumio[1232]: BT PLUGIN MESSAGE: VOLATILE: tidalconnect Apr 02 03:53:48 mboss-2 volumio[1232]: BT PLUGIN MESSAGE: STATE:undefined Apr 02 03:53:48 mboss-2 sudo[8882]: pam_unix(sudo:session): session closed for user root Apr 02 03:53:48 mboss-2 volumio[1232]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Apr 02 03:53:48 mboss-2 volumio[1232]: BT PLUGIN MESSAGE: Playing: false Apr 02 03:53:48 mboss-2 volumio[1232]: BT PLUGIN MESSAGE: VOLATILE: tidalconnect Apr 02 03:53:48 mboss-2 volumio[1232]: BT PLUGIN MESSAGE: STATE:undefined Apr 02 03:53:48 mboss-2 autossh[8889]: port set to 0, monitoring disabled Apr 02 03:53:48 mboss-2 autossh[8889]: starting ssh (count 1) Apr 02 03:53:48 mboss-2 autossh[8889]: ssh child pid is 8895 Apr 02 03:53:48 mboss-2 volumio[1232]: info: Remote SSH Started Apr 02 03:53:48 mboss-2 volumio[1232]: info: CoreCommandRouter::volumioGetState Apr 02 03:53:49 mboss-2 volumiossh-tunnel[8888]: Warning: Permanently added '[as1.myvolumio.org]:2222,[128.199.166.162]:2222' (RSA) to the list of known hosts. Apr 02 03:54:52 mboss-2 volumio[1367]: [Vollibrespot] : Connecting to AP "ap-gae2.spotify.com:443" Apr 02 03:54:52 mboss-2 volumio[1367]: [Vollibrespot] : Authenticated as "inc341pp57iwnys7n1zbibb2a" ! Apr 02 03:54:52 mboss-2 volumio[1367]: [Vollibrespot] : Setting up new mixer: card:hw:2 mixer:SoftMaster index:0 Apr 02 03:54:52 mboss-2 volumio[1367]: [Vollibrespot] : Alsa min-db is not SND_CTL_TLV_DB_GAIN_MUTE!! Apr 02 03:54:52 mboss-2 volumio[1367]: [Vollibrespot] : Alsa Mixer info min: 0 (MilliBel(0)[dB]) -- max: 99 (MilliBel(0)[dB]) HW: false Apr 02 03:54:52 mboss-2 volumio[1367]: [Vollibrespot] : Using Alsa linear volume Apr 02 03:54:52 mboss-2 volumio[1367]: [Vollibrespot] : Alsa min-db is not SND_CTL_TLV_DB_GAIN_MUTE!! Apr 02 03:54:52 mboss-2 volumio[1367]: [Vollibrespot] : Using alsa sink Apr 02 03:54:52 mboss-2 volumio[1367]: [Vollibrespot] : Metadata pipe established Apr 02 03:54:52 mboss-2 volumio[1367]: [Vollibrespot] : Event: Volume { volume_to_mixer: 65535 } Apr 02 03:54:52 mboss-2 volumio[1367]: [Vollibrespot] : Country: "VN" Apr 02 03:54:52 mboss-2 volumio[1232]: [SpotifyConnect] 100 Apr 02 03:54:52 mboss-2 volumio[1232]: [SpotifyConnect] Volume: Spotify:100 Volumio: 100 Apr 02 03:54:52 mboss-2 volumio[1232]: info: CoreStateMachine::pushState Apr 02 03:54:52 mboss-2 volumio[1232]: info: CoreCommandRouter::volumioPushState Apr 02 03:54:52 mboss-2 volumio[1232]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 02 03:54:53 mboss-2 volumio[1367]: [Vollibrespot] : Fetching autoplay context uri Apr 02 03:54:53 mboss-2 volumio[1367]: [Vollibrespot] : Event: SessionActive { became_active_at: 1712030093221 } Apr 02 03:54:53 mboss-2 volumio[1367]: [Vollibrespot] : SessionActive! Apr 02 03:54:53 mboss-2 volumio[1367]: [Vollibrespot] : Event: PlaybackStarted { track_id: SpotifyId { id: 144952985756387918676855102000046812606, audio_type: Track } } Apr 02 03:54:53 mboss-2 volumio[1367]: [Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 144952985756387918676855102000046812606, audio_type: Track } } Apr 02 03:54:53 mboss-2 volumio[1232]: [SpotifyConnect] A connect session has begun Apr 02 03:54:53 mboss-2 volumio[1232]: [SpotifyConnect] Device palyback is active! Apr 02 03:54:53 mboss-2 volumio[1232]: info: CoreCommandRouter::volumioGetState Apr 02 03:54:53 mboss-2 volumio[1232]: [SpotifyConnect] Currently active: tidalconnect Apr 02 03:54:53 mboss-2 volumio[1232]: [SpotifyConnect] Stopping currently active service Apr 02 03:54:53 mboss-2 volumio[1232]: info: CoreCommandRouter::volumioStop Apr 02 03:54:53 mboss-2 volumio[1232]: info: CoreStateMachine::stop Apr 02 03:54:53 mboss-2 volumio[1232]: info: CoreStateMachine::serviceStop Apr 02 03:54:53 mboss-2 volumio[1232]: info: CoreCommandRouter::serviceStop Apr 02 03:54:53 mboss-2 volumio[1232]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 02 03:54:53 mboss-2 volumio[1232]: TypeError: Cannot read property 'then' of undefined Apr 02 03:54:53 mboss-2 volumio[1232]: at SpotConnEvents.SpotConn.on (/data/plugins/music_service/volspotconnect2/index.js:143:23) Apr 02 03:54:53 mboss-2 volumio[1232]: at emitNone (events.js:106:13) Apr 02 03:54:53 mboss-2 volumio[1232]: at SpotConnEvents.emit (events.js:208:7) Apr 02 03:54:53 mboss-2 volumio[1232]: at SpotConnEvents.parseData (/data/plugins/music_service/volspotconnect2/SpotConnController.js:73:16) Apr 02 03:54:53 mboss-2 volumio[1232]: at Socket.SpotConnEvents._udpsource.on.msg (/data/plugins/music_service/volspotconnect2/SpotConnController.js:15:12) Apr 02 03:54:53 mboss-2 volumio[1232]: at emitTwo (events.js:126:13) Apr 02 03:54:53 mboss-2 volumio[1232]: at Socket.emit (events.js:214:7) Apr 02 03:54:53 mboss-2 volumio[1232]: at UDP.onMessage [as onmessage] (dgram.js:659:8) Apr 02 03:54:53 mboss-2 volumio[1232]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 02 03:54:53 mboss-2 volumio[1367]: [Vollibrespot] : error 400 for uri hm://autoplay-enabled/query?uri=spotify:search:%C4%90%E1%BB%A9c+Tu%E1%BA%A5n%2C+Sang+ Apr 02 03:54:53 mboss-2 volumio[1367]: [Vollibrespot] : AutoplayError: MercuryError Apr 02 03:54:53 mboss-2 volumio[1367]: [Vollibrespot] : Event: GotToken { token: Token { access_token: "BQCbIeWwfmuwjA53lamAZsJYX387UOQlW-MIzFRG8BTBf3wp39KanMptfVeTEeMDfesnqlUf1bzY8DQUH4VFp7_V--zGnowfhFjFYOfLtn6SSVy8b18svpdWqzf1NeABilVQJRzYNydCzP1I6L5qBD6oFibPi31L4tsYelpnI6pMYcsCOGorrviYCzf0CX2z2qYsbsAwnEjew4XFSowtdXVcDw", expires_in: 3600, token_type: "Bearer", scope: ["streaming", "user-read-playback-state", "user-modify-playback-state", "user-read-currently-playing", "user-read-private"] } } Apr 02 03:54:53 mboss-2 vtcs[1652]: [2024-04-02 03:54:53] [info] asio async_shutdown error: asio.misc:2 (End of file) Apr 02 03:54:53 mboss-2 volumio[1367]: [Vollibrespot] : Loading with Spotify URI Apr 02 03:54:53 mboss-2 sudo[9200]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-02 03:53 Apr 02 03:54:53 mboss-2 sudo[9200]: 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="14acf028cf46278bd3fd3dd02523424a9bc825bf" VOLUMIO_FE_VERSION="74f64fbba9dc8053dc27ed7125863d6ad6533965" VOLUMIO_BE_VERSION="0a6008ded215bf284d5d4cd9c4df3333cb320899" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat Apr 24 17:39:58 CEST 2021" VOLUMIO_VERSION="2.882" VOLUMIO_HARDWARE="pi" VOLUMIO_HASH="1a98a01eef5aa5927a5874c2d3c1b0dc"