-- Logs begin at Mon 2025-07-14 06:21:21 BST, end at Wed 2025-07-16 19:55:31 BST. -- Jul 16 19:54:01 volumio-shiny kernel: hwmon hwmon1: Voltage normalised Jul 16 19:54:05 volumio-shiny kernel: hwmon hwmon1: Undervoltage detected! Jul 16 19:54:11 volumio-shiny kernel: hwmon hwmon1: Voltage normalised Jul 16 19:54:15 volumio-shiny kernel: hwmon hwmon1: Undervoltage detected! Jul 16 19:54:21 volumio-shiny kernel: hwmon hwmon1: Voltage normalised Jul 16 19:54:26 volumio-shiny kernel: hwmon hwmon1: Undervoltage detected! Jul 16 19:54:32 volumio-shiny kernel: hwmon hwmon1: Voltage normalised Jul 16 19:54:36 volumio-shiny kernel: hwmon hwmon1: Undervoltage detected! Jul 16 19:54:40 volumio-shiny kernel: hwmon hwmon1: Voltage normalised Jul 16 19:54:46 volumio-shiny kernel: hwmon hwmon1: Undervoltage detected! Jul 16 19:54:51 volumio-shiny kernel: hwmon hwmon1: Voltage normalised Jul 16 19:54:55 volumio-shiny kernel: hwmon hwmon1: Undervoltage detected! Jul 16 19:55:01 volumio-shiny kernel: hwmon hwmon1: Voltage normalised Jul 16 19:55:05 volumio-shiny kernel: hwmon hwmon1: Undervoltage detected! Jul 16 19:55:11 volumio-shiny kernel: hwmon hwmon1: Voltage normalised Jul 16 19:55:16 volumio-shiny kernel: hwmon hwmon1: Undervoltage detected! Jul 16 19:55:22 volumio-shiny kernel: hwmon hwmon1: Voltage normalised Jul 16 19:55:26 volumio-shiny kernel: hwmon hwmon1: Undervoltage detected! Jul 16 19:55:28 volumio-shiny volumio[1581]: [Vollibrespot] : Connecting to AP "ap-gew1.spotify.com:443" Jul 16 19:55:29 volumio-shiny volumio[1581]: [Vollibrespot] : Authenticated as "a36e9qdeev8ub5w3rrgolrqwm" ! Jul 16 19:55:29 volumio-shiny volumio[1581]: [Vollibrespot] : Using alsa sink Jul 16 19:55:29 volumio-shiny volumio[1581]: [Vollibrespot] : Metadata pipe established Jul 16 19:55:29 volumio-shiny volumio[1581]: [Vollibrespot] : Country: "GB" Jul 16 19:55:29 volumio-shiny volumio[1581]: [Vollibrespot] : Event: Volume { volume_to_mixer: 21626 } Jul 16 19:55:29 volumio-shiny volumio[978]: [SpotifyConnect] 32.99916075379568 Jul 16 19:55:29 volumio-shiny volumio[978]: [SpotifyConnect] Volume: Spotify:32.99916075379568 Volumio: 33 Jul 16 19:55:29 volumio-shiny volumio[978]: info: CoreStateMachine::pushState Jul 16 19:55:29 volumio-shiny volumio[978]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 16 19:55:29 volumio-shiny volumio[978]: info: CoreCommandRouter::volumioPushState Jul 16 19:55:29 volumio-shiny volumio[978]: info: MRS: Pushing multiroomSync output update for this device Jul 16 19:55:29 volumio-shiny volumio[978]: info: MRS: Pushing multiroomSync output Jul 16 19:55:29 volumio-shiny volumio[1581]: [Vollibrespot] : Event: SessionActive { became_active_at: 1752692129789 } Jul 16 19:55:29 volumio-shiny volumio[1581]: [Vollibrespot] : Fetching autoplay context uri Jul 16 19:55:29 volumio-shiny volumio[1581]: [Vollibrespot] : SessionActive! Jul 16 19:55:29 volumio-shiny volumio[1581]: [Vollibrespot] : Event: PlaybackStarted { track_id: SpotifyId { id: 193268306430098655904102206508609082841, audio_type: Track } } Jul 16 19:55:29 volumio-shiny volumio[1581]: [Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 193268306430098655904102206508609082841, audio_type: Track } } Jul 16 19:55:29 volumio-shiny volumio[978]: [SpotifyConnect] A connect session has begun Jul 16 19:55:29 volumio-shiny volumio[978]: [SpotifyConnect] Device palyback is active! Jul 16 19:55:29 volumio-shiny volumio[978]: info: CoreCommandRouter::volumioGetState Jul 16 19:55:29 volumio-shiny volumio[978]: [SpotifyConnect] Currently active: tidalconnect Jul 16 19:55:29 volumio-shiny volumio[978]: [SpotifyConnect] Stopping currently active service Jul 16 19:55:29 volumio-shiny volumio[978]: info: CoreCommandRouter::volumioStop Jul 16 19:55:29 volumio-shiny volumio[978]: info: CoreStateMachine::stop Jul 16 19:55:29 volumio-shiny volumio[978]: info: CoreStateMachine::serviceStop Jul 16 19:55:29 volumio-shiny volumio[978]: info: CoreCommandRouter::serviceStop Jul 16 19:55:29 volumio-shiny volumio[1581]: [Vollibrespot] : error 400 for uri hm://autoplay-enabled/query?uri=spotify:search:the+choice Jul 16 19:55:29 volumio-shiny volumio[1581]: [Vollibrespot] : AutoplayError: MercuryError Jul 16 19:55:29 volumio-shiny volumio[978]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 16 19:55:29 volumio-shiny volumio[1581]: [Vollibrespot] : Event: GotToken { token: Token { access_token: "BQBFZBR5vGQrvoufYoZrGHM0ZifmuaVhRnMv5BjoAMM5MGeUNVahi2EoAfXGV65JSRj34ffMcvo-DT9Xri7RE9DbRpGNMg3gWfTvacdjhRpZW2v7PLDwZeMj9JQ83OPqXpE4S87q5denfNlwJ7dcPByKarOrP47tmsXEdVrnzZr1CQhdeWyvutzJBndpHkixH4Jx3WrTaR9ewkl43eNg5GvOWogTlpcYmnJ8-xf844dQUpWwmEr9jwjsXUYWaiAr4Q", expires_in: 3600, token_type: "Bearer", scope: ["streaming", "user-modify-playback-state", "user-read-playback-state", "user-read-currently-playing", "user-read-private"] } } Jul 16 19:55:29 volumio-shiny volumio[978]: TypeError: Cannot read property 'then' of undefined Jul 16 19:55:29 volumio-shiny volumio[978]: at SpotConnEvents. (/data/plugins/music_service/volspotconnect2/index.js:143:23) Jul 16 19:55:29 volumio-shiny volumio[978]: at SpotConnEvents.emit (events.js:315:20) Jul 16 19:55:29 volumio-shiny volumio[978]: at SpotConnEvents.parseData (/data/plugins/music_service/volspotconnect2/SpotConnController.js:73:16) Jul 16 19:55:29 volumio-shiny volumio[978]: at Socket. (/data/plugins/music_service/volspotconnect2/SpotConnController.js:15:12) Jul 16 19:55:29 volumio-shiny volumio[978]: at Socket.emit (events.js:315:20) Jul 16 19:55:29 volumio-shiny volumio[978]: at UDP.onMessage [as onmessage] (dgram.js:919:8) Jul 16 19:55:29 volumio-shiny volumio[978]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 16 19:55:29 volumio-shiny volumio[1581]: [Vollibrespot] : Loading with Spotify URI Jul 16 19:55:30 volumio-shiny volumio[1581]: [Vollibrespot] : (248184 ms) loaded Jul 16 19:55:30 volumio-shiny volumio[1581]: [Vollibrespot] : Event: SinkActive Jul 16 19:55:31 volumio-shiny sudo[20969]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-16 19:54 Jul 16 19:55:31 volumio-shiny sudo[20969]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 24 Apr 2025 09:33:57 AM CEST" VOLUMIO_VERSION="3.804" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="354f95cf0a6c2cbcd57b1aca3179c81c"