-- Logs begin at Wed 2026-03-18 20:20:56 UTC, end at Tue 2026-03-24 12:19:41 UTC. -- Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::servicePushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreStateMachine::pushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::volumioPushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 12:19:18 volumio-hi-end kernel: aotg_hub_endpoint_disable Mar 24 12:19:18 volumio-hi-end kernel: aotg_hcd aotg_hcd.0: ep1 index 1 from ep [out] Mar 24 12:19:18 volumio-hi-end kernel: aotg_hub_endpoint_disable Mar 24 12:19:18 volumio-hi-end kernel: aotg_hcd aotg_hcd.0: ep1 index 3 from ep [in] Mar 24 12:19:18 volumio-hi-end volumio[787]: info: Pushing metadata Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::servicePushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreStateMachine::pushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::volumioPushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::servicePushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreStateMachine::pushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::volumioPushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::servicePushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreStateMachine::pushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::volumioPushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::servicePushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreStateMachine::pushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::volumioPushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 12:19:18 volumio-hi-end volumio[787]: info: touch_display: Setting screensaver timeout to 120 seconds. Mar 24 12:19:18 volumio-hi-end volumio[787]: info: Pushing metadata Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::servicePushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreStateMachine::pushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::volumioPushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::servicePushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreStateMachine::pushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::volumioPushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::servicePushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreStateMachine::pushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::volumioPushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::servicePushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreStateMachine::pushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::volumioPushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::servicePushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreStateMachine::pushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::volumioPushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::servicePushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreStateMachine::pushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::volumioPushState Mar 24 12:19:18 volumio-hi-end volumio[787]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 12:19:18 volumio-hi-end volumio[787]: info: touch_display: Setting screensaver timeout to 120 seconds. Mar 24 12:19:18 volumio-hi-end volumio[787]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Mar 24 12:19:18 volumio-hi-end volumio[787]: info: touch_display: Setting screensaver timeout to 120 seconds. Mar 24 12:19:19 volumio-hi-end volumio[787]: info: CoreCommandRouter::servicePushState Mar 24 12:19:19 volumio-hi-end vtcs[1251]: VTCS: PCM: plughw:1,0 RATE: 44100 FORMAT: S16_LE CHANNELS: 2 PERIODSIZE: 4096 BUFFERSIZE: 32768 Mar 24 12:19:19 volumio-hi-end kernel: snd_pcm_mmap,default Mar 24 12:19:19 volumio-hi-end kernel: iso_packets:0, bInterval:1, urb_interval:1, reg_con:0x4 Mar 24 12:19:19 volumio-hi-end kernel: iso_packets:0, bInterval:4, urb_interval:8, reg_con:0x4 Mar 24 12:19:19 volumio-hi-end volumio[787]: info: CoreStateMachine::pushState Mar 24 12:19:19 volumio-hi-end volumio[787]: info: CoreCommandRouter::volumioPushState Mar 24 12:19:19 volumio-hi-end volumio[787]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 12:19:19 volumio-hi-end volumio[787]: info: CoreCommandRouter::servicePushState Mar 24 12:19:19 volumio-hi-end volumio[787]: info: CoreStateMachine::pushState Mar 24 12:19:19 volumio-hi-end volumio[787]: info: CoreCommandRouter::volumioPushState Mar 24 12:19:19 volumio-hi-end volumio[787]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 12:19:22 volumio-hi-end volumio[787]: info: CoreCommandRouter::servicePushState Mar 24 12:19:22 volumio-hi-end volumio[787]: info: CoreStateMachine::pushState Mar 24 12:19:22 volumio-hi-end volumio[787]: info: CoreCommandRouter::volumioPushState Mar 24 12:19:22 volumio-hi-end volumio[787]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 12:19:22 volumio-hi-end volumio[787]: info: touch_display: Setting screensaver timeout to 120 seconds. Mar 24 12:19:28 volumio-hi-end volumio[787]: info: Tunnel connection is inactive, restarting it Mar 24 12:19:28 volumio-hi-end volumio[787]: info: Starting Tunnel 1 Mar 24 12:19:28 volumio-hi-end volumio[787]: info: Starting Tunnel Connection Checker Mar 24 12:19:28 volumio-hi-end sudo[2479]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Mar 24 12:19:28 volumio-hi-end sudo[2479]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 12:19:28 volumio-hi-end systemd[1]: Stopping MyVolumio SSH Tunnel... Mar 24 12:19:28 volumio-hi-end autossh[1992]: received signal to exit (15) Mar 24 12:19:28 volumio-hi-end systemd[1]: Starting MyVolumio SSH Tunnel... Mar 24 12:19:28 volumio-hi-end systemd[1]: Started MyVolumio SSH Tunnel. Mar 24 12:19:28 volumio-hi-end sudo[2479]: pam_unix(sudo:session): session closed for user root Mar 24 12:19:28 volumio-hi-end volumio[787]: info: Remote SSH Started Mar 24 12:19:28 volumio-hi-end autossh[2483]: port set to 0, monitoring disabled Mar 24 12:19:28 volumio-hi-end autossh[2483]: starting ssh (count 1) Mar 24 12:19:28 volumio-hi-end autossh[2483]: ssh child pid is 2486 Mar 24 12:19:28 volumio-hi-end volumio[787]: info: CoreCommandRouter::volumioGetState Mar 24 12:19:29 volumio-hi-end volumiossh-tunnel[2482]: Warning: Permanently added '[us1.myvolumio.org]:2222,[162.243.167.188]:2222' (RSA) to the list of known hosts. Mar 24 12:19:36 volumio-hi-end volumio[966]: [Vollibrespot] : Connecting to AP "ap-guc3.spotify.com:443" Mar 24 12:19:37 volumio-hi-end volumio[966]: [Vollibrespot] : Authenticated as "11167516964" ! Mar 24 12:19:37 volumio-hi-end volumio[966]: [Vollibrespot] : Setting up new mixer: card:hw:1 mixer:Pro-Ject Clock Selector index:0 Mar 24 12:19:37 volumio-hi-end volumio[966]: [Vollibrespot] : Alsa min-db is not SND_CTL_TLV_DB_GAIN_MUTE!! Mar 24 12:19:37 volumio-hi-end volumio[966]: [Vollibrespot] : Alsa Mixer info min: 0 (MilliBel(-12700)[dB]) -- max: 127 (MilliBel(0)[dB]) HW: true Mar 24 12:19:37 volumio-hi-end volumio[966]: [Vollibrespot] : Alsa min-db is not SND_CTL_TLV_DB_GAIN_MUTE!! Mar 24 12:19:37 volumio-hi-end volumio[966]: [Vollibrespot] : Using alsa sink Mar 24 12:19:37 volumio-hi-end volumio[966]: [Vollibrespot] : Metadata pipe established Mar 24 12:19:37 volumio-hi-end volumio[966]: [Vollibrespot] : Country: "AR" Mar 24 12:19:37 volumio-hi-end volumio[966]: [Vollibrespot] : Event: Volume { volume_to_mixer: 65535 } Mar 24 12:19:37 volumio-hi-end volumio[787]: [SpotifyConnect] 100 Mar 24 12:19:37 volumio-hi-end volumio[787]: [SpotifyConnect] Volume: Spotify:100 Volumio: 100 Mar 24 12:19:37 volumio-hi-end volumio[787]: info: CoreStateMachine::pushState Mar 24 12:19:37 volumio-hi-end volumio[787]: info: CoreCommandRouter::volumioPushState Mar 24 12:19:37 volumio-hi-end volumio[787]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 12:19:38 volumio-hi-end volumio[966]: [Vollibrespot] : Event: SessionActive { became_active_at: 1774354778603 } Mar 24 12:19:38 volumio-hi-end volumio[966]: [Vollibrespot] : SessionActive! Mar 24 12:19:38 volumio-hi-end volumio[787]: [SpotifyConnect] A connect session has begun Mar 24 12:19:38 volumio-hi-end volumio[966]: [Vollibrespot] : Fetching autoplay context uri Mar 24 12:19:38 volumio-hi-end volumio[966]: [Vollibrespot] : No more tracks left in queue Mar 24 12:19:38 volumio-hi-end volumio[966]: [Vollibrespot] : No autoplay_uri found Mar 24 12:19:38 volumio-hi-end volumio[966]: [Vollibrespot] : AutoplayError: MercuryError Mar 24 12:19:39 volumio-hi-end volumio[966]: [Vollibrespot] : Event: GotToken { token: Token { access_token: "BQDd7yYft-U4ZK-gHyG5NP22BUZJmAGYz2-Q4QLq_Y9ISCpgYJqqgq8C1EFyt45UL2J_7691mV5hohp9tt0jejMcOdrBxV3zeoQQ3Q6qeomlNUGMQQ3IrnNzk3AeO98plMKcqrffLyPYnh6ZcFzX1qxOxn8Qt3OdM6OIVTHZTfbS_GVNXjG-hxmYKHG1ZmPHSNv5bPE2tl0FsJh6eNFf3-z3tqN6sj07qsZXImu4mVvp6764wW4E", expires_in: 3600, token_type: "Bearer", scope: ["streaming", "user-modify-playback-state", "user-read-playback-state", "user-read-currently-playing", "user-read-private"] } } Mar 24 12:19:39 volumio-hi-end volumio[787]: [SpotifyConnect] BQDd7yYft-U4ZK-gHyG5NP22BUZJmAGYz2-Q4QLq_Y9ISCpgYJqqgq8C1EFyt45UL2J_7691mV5hohp9tt0jejMcOdrBxV3zeoQQ3Q6qeomlNUGMQQ3IrnNzk3AeO98plMKcqrffLyPYnh6ZcFzX1qxOxn8Qt3OdM6OIVTHZTfbS_GVNXjG-hxmYKHG1ZmPHSNv5bPE2tl0FsJh6eNFf3-z3tqN6sj07qsZXImu4mVvp6764wW4E Mar 24 12:19:39 volumio-hi-end volumio[966]: [Vollibrespot] : Fetching autoplay context uri Mar 24 12:19:39 volumio-hi-end volumio[966]: [Vollibrespot] : Event: PlaybackStarted { track_id: SpotifyId { id: 226573467999647583579292849110733338480, audio_type: Track } } Mar 24 12:19:39 volumio-hi-end volumio[966]: [Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 226573467999647583579292849110733338480, audio_type: Track } } Mar 24 12:19:39 volumio-hi-end volumio[787]: [SpotifyConnect] Device palyback is active! Mar 24 12:19:39 volumio-hi-end volumio[787]: info: CoreCommandRouter::volumioGetState Mar 24 12:19:39 volumio-hi-end volumio[787]: [SpotifyConnect] Currently active: tidalconnect Mar 24 12:19:39 volumio-hi-end volumio[787]: [SpotifyConnect] Stopping currently active service Mar 24 12:19:39 volumio-hi-end volumio[787]: info: CoreCommandRouter::volumioStop Mar 24 12:19:39 volumio-hi-end volumio[787]: info: CoreStateMachine::stop Mar 24 12:19:39 volumio-hi-end volumio[787]: info: CoreStateMachine::serviceStop Mar 24 12:19:39 volumio-hi-end volumio[787]: info: CoreCommandRouter::serviceStop Mar 24 12:19:39 volumio-hi-end volumio[787]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 12:19:39 volumio-hi-end volumio[787]: TypeError: Cannot read property 'then' of undefined Mar 24 12:19:39 volumio-hi-end volumio[787]: at SpotConnEvents.SpotConn.on (/data/plugins/music_service/volspotconnect2/index.js:143:23) Mar 24 12:19:39 volumio-hi-end volumio[787]: at emitNone (events.js:106:13) Mar 24 12:19:39 volumio-hi-end volumio[787]: at SpotConnEvents.emit (events.js:208:7) Mar 24 12:19:39 volumio-hi-end volumio[787]: at SpotConnEvents.parseData (/data/plugins/music_service/volspotconnect2/SpotConnController.js:73:16) Mar 24 12:19:39 volumio-hi-end volumio[787]: at Socket.SpotConnEvents._udpsource.on.msg (/data/plugins/music_service/volspotconnect2/SpotConnController.js:15:12) Mar 24 12:19:39 volumio-hi-end volumio[787]: at emitTwo (events.js:126:13) Mar 24 12:19:39 volumio-hi-end volumio[787]: at Socket.emit (events.js:214:7) Mar 24 12:19:39 volumio-hi-end volumio[787]: at UDP.onMessage [as onmessage] (dgram.js:659:8) Mar 24 12:19:39 volumio-hi-end kernel: aotg_hub_endpoint_disable Mar 24 12:19:39 volumio-hi-end kernel: aotg_hcd aotg_hcd.0: ep1 index 1 from ep [out] Mar 24 12:19:39 volumio-hi-end kernel: aotg_hub_endpoint_disable Mar 24 12:19:39 volumio-hi-end kernel: aotg_hcd aotg_hcd.0: ep1 index 3 from ep [in] Mar 24 12:19:39 volumio-hi-end volumio[787]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 12:19:39 volumio-hi-end vtcs[1251]: [2026-03-24 12:19:39] [info] asio async_shutdown error: asio.misc:2 (End of file) Mar 24 12:19:39 volumio-hi-end volumio[966]: [Vollibrespot] : error 400 for uri hm://autoplay-enabled/query?uri=spotify:search:juan+paco+ Mar 24 12:19:39 volumio-hi-end volumio[966]: [Vollibrespot] : AutoplayError: MercuryError Mar 24 12:19:39 volumio-hi-end volumio[966]: [Vollibrespot] : Loading with Spotify URI Mar 24 12:19:40 volumio-hi-end volumio[966]: [Vollibrespot] : (143354 ms) loaded Mar 24 12:19:40 volumio-hi-end volumio[966]: [Vollibrespot] : Event: SinkActive Mar 24 12:19:40 volumio-hi-end kernel: snd_pcm_mmap,default Mar 24 12:19:40 volumio-hi-end kernel: iso_packets:0, bInterval:1, urb_interval:1, reg_con:0x4 Mar 24 12:19:40 volumio-hi-end kernel: iso_packets:0, bInterval:4, urb_interval:8, reg_con:0x4 Mar 24 12:19:41 volumio-hi-end sudo[2524]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-03-24 12:18 Mar 24 12:19:41 volumio-hi-end sudo[2524]: 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="307f91893fca011201acba9973e1c41bd3a0ad5d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Oct 1 12:12:00 CEST 2021" VOLUMIO_VERSION="2.916" VOLUMIO_HARDWARE="sparky" VOLUMIO_HASH="1507c65028120e16c14994c066bc5dd4"