-- Logs begin at Thu 2025-02-20 02:53:38 MST, end at Sun 2025-02-23 15:24:52 MST. -- Feb 23 15:23:03 apolo sshd[20401]: Accepted password for volumio from 192.168.1.151 port 25839 ssh2 Feb 23 15:23:03 apolo sshd[20401]: pam_unix(sshd:session): session opened for user volumio by (uid=0) Feb 23 15:23:03 apolo systemd[1]: Created slice User Slice of UID 1000. Feb 23 15:23:03 apolo systemd[1]: Starting User Runtime Directory /run/user/1000... Feb 23 15:23:03 apolo systemd-logind[566]: New session 1 of user volumio. Feb 23 15:23:03 apolo systemd[1]: Started User Runtime Directory /run/user/1000. Feb 23 15:23:03 apolo systemd[1]: Starting User Manager for UID 1000... Feb 23 15:23:04 apolo systemd[20423]: pam_unix(systemd-user:session): session opened for user volumio by (uid=0) Feb 23 15:23:04 apolo sshd[20420]: Accepted password for volumio from 192.168.1.151 port 25840 ssh2 Feb 23 15:23:04 apolo sshd[20420]: pam_unix(sshd:session): session opened for user volumio by (uid=0) Feb 23 15:23:04 apolo systemd-logind[566]: New session 3 of user volumio. Feb 23 15:23:04 apolo systemd[20423]: Starting D-Bus User Message Bus Socket. Feb 23 15:23:04 apolo systemd[20423]: Reached target Timers. Feb 23 15:23:04 apolo systemd[20423]: Listening on Sound System. Feb 23 15:23:04 apolo systemd[20423]: Listening on GnuPG cryptographic agent (ssh-agent emulation). Feb 23 15:23:04 apolo systemd[20423]: Listening on GnuPG network certificate management daemon. Feb 23 15:23:04 apolo systemd[20423]: Listening on GnuPG cryptographic agent and passphrase cache (restricted). Feb 23 15:23:04 apolo systemd[20423]: Listening on GnuPG cryptographic agent and passphrase cache. Feb 23 15:23:04 apolo systemd[20423]: Reached target Paths. Feb 23 15:23:04 apolo systemd[20423]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers). Feb 23 15:23:04 apolo systemd[20423]: Listening on D-Bus User Message Bus Socket. Feb 23 15:23:04 apolo systemd[20423]: Reached target Sockets. Feb 23 15:23:04 apolo systemd[20423]: Reached target Basic System. Feb 23 15:23:04 apolo systemd[20423]: Reached target Default. Feb 23 15:23:04 apolo systemd[20423]: Startup finished in 328ms. Feb 23 15:23:04 apolo systemd[1]: Started User Manager for UID 1000. Feb 23 15:23:04 apolo systemd[1]: Started Session 3 of user volumio. Feb 23 15:23:04 apolo systemd[1]: Started Session 1 of user volumio. Feb 23 15:23:09 apolo go-librespot[16212]: time="2025-02-23T15:23:09-07:00" level=trace msg="received accesspoint ping" Feb 23 15:23:09 apolo go-librespot[16212]: time="2025-02-23T15:23:09-07:00" level=trace msg="received accesspoint pong ack" Feb 23 15:23:09 apolo go-librespot[16212]: time="2025-02-23T15:23:09-07:00" level=error msg="did not receive last pong from dealer, 1650s passed" Feb 23 15:23:39 apolo go-librespot[16212]: time="2025-02-23T15:23:39-07:00" level=error msg="did not receive last pong from dealer, 1680s passed" Feb 23 15:23:51 apolo volumio[1008]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Feb 23 15:23:51 apolo volumio[1008]: info: Downloading plugin at http://127.0.0.1:3000/plugin-serve/volspotconnect2.zip Feb 23 15:23:51 apolo volumio[1008]: info: END DOWNLOAD: http://127.0.0.1:3000/plugin-serve/volspotconnect2.zip Feb 23 15:23:51 apolo volumio[1008]: info: Folder /tmp/plugins removed Feb 23 15:23:52 apolo volumio[1008]: info: Check plugin dependencies Feb 23 15:23:52 apolo volumio[1008]: info: Checking if plugin already exists Feb 23 15:23:52 apolo volumio[1008]: info: Rename folder Feb 23 15:23:52 apolo volumio[1008]: info: Folder /tmp/downloaded_plugin.zip removed Feb 23 15:23:52 apolo volumio[1008]: info: Move to category Feb 23 15:23:58 apolo volumio[1008]: info: Checking if install.sh is present Feb 23 15:23:58 apolo volumio[1008]: info: Executing install.sh Feb 23 15:23:58 apolo sudo[20931]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/music_service/volspotconnect2/install.sh Feb 23 15:23:58 apolo sudo[20931]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 23 15:23:58 apolo volumio[1008]: info: Launching a bash shell Feb 23 15:23:58 apolo volumio[1008]: info: Installing volspotconnect2 dependencies Feb 23 15:23:58 apolo volumio[1008]: info: Detected cpu architecture as armv7l Feb 23 15:23:59 apolo volumio[1008]: info: Latest version: v0.2.5 Requested version: v0.2.2 Feb 23 15:23:59 apolo volumio[1008]: info: Supported device (arch = armv7l), downloading required packages for vollibrespot v0.2.2 Feb 23 15:23:59 apolo volumio[1008]: info: Downloading file Feb 23 15:24:00 apolo volumio[1008]: info: Extracting... Feb 23 15:24:00 apolo volumio[1008]: info: -rw-r--r-- 1 root root 4289193 Feb 23 15:24 vollibrespot-armv7l.tar.xz Feb 23 15:24:01 apolo volumio[1008]: info: vollibrespot v0.2.2 cd96399 2020-10-07 (librespot 08d8bcc 2020-10-07) -- Built On 2020-10-07 Feb 23 15:24:01 apolo sudo[20974]: root : TTY=unknown ; PWD=/data/plugins/music_service/volspotconnect2 ; USER=root ; COMMAND=/bin/tar -xvf volspotconnect2.service.tar -C / Feb 23 15:24:01 apolo sudo[20974]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 23 15:24:01 apolo volumio[1008]: info: etc/systemd/system/volspotconnect2.service Feb 23 15:24:01 apolo sudo[20974]: pam_unix(sudo:session): session closed for user root Feb 23 15:24:01 apolo sudo[20976]: root : TTY=unknown ; PWD=/data/plugins/music_service/volspotconnect2 ; USER=root ; COMMAND=/bin/chmod +x /data/plugins/music_service/volspotconnect2/onstart1.sh Feb 23 15:24:01 apolo sudo[20976]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 23 15:24:01 apolo sudo[20976]: pam_unix(sudo:session): session closed for user root Feb 23 15:24:01 apolo sudo[20931]: pam_unix(sudo:session): session closed for user root Feb 23 15:24:01 apolo volumio[1008]: info: volspotconnect2 installed Feb 23 15:24:01 apolo volumio[1008]: Plugin install end detected on script Feb 23 15:24:01 apolo volumio[1008]: info: Install script completed Feb 23 15:24:01 apolo volumio[1008]: info: Adding reference to registry Feb 23 15:24:01 apolo volumio[1008]: info: Done installing plugin. Feb 23 15:24:01 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 23 15:24:01 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 23 15:24:01 apolo volumio[1008]: info: Folder /tmp/plugins removed Feb 23 15:24:01 apolo volumio[1008]: info: Folder /tmp/downloaded_plugin.zip removed Feb 23 15:24:01 apolo volumio[1008]: info: Folder /data/temp removed Feb 23 15:24:09 apolo go-librespot[16212]: time="2025-02-23T15:24:09-07:00" level=error msg="did not receive last pong from dealer, 1710s passed" Feb 23 15:24:19 apolo volumio[1008]: verbose: New Socket.io Connection to 192.168.1.107 from 192.168.1.151 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:135.0) Gecko/20100101 Firefox/135.0 Engine version: 3 Transport: polling Total Clients: 5 Feb 23 15:24:19 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 23 15:24:19 apolo volumio[1008]: info: CoreCommandRouter::volumioGetVisibleSources Feb 23 15:24:19 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 15:24:19 apolo volumio[1008]: info: CoreCommandRouter::volumioGetState Feb 23 15:24:19 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Feb 23 15:24:19 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 23 15:24:19 apolo volumio[1008]: info: Received Get System Info Feb 23 15:24:19 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 15:24:19 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 15:24:19 apolo volumio[1008]: info: Discovery: Getting this device information Feb 23 15:24:19 apolo volumio[1008]: info: CoreCommandRouter::volumioGetState Feb 23 15:24:19 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 15:24:19 apolo volumio[1008]: info: CoreCommandRouter::volumioGetState Feb 23 15:24:19 apolo volumio[1008]: info: Listing playlists Feb 23 15:24:19 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Feb 23 15:24:19 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 23 15:24:19 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Feb 23 15:24:20 apolo volumio[1008]: info: CoreCommandRouter::volumioGetState Feb 23 15:24:21 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Feb 23 15:24:21 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 23 15:24:21 apolo volumio[1008]: info: Received Get System Info Feb 23 15:24:21 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 15:24:21 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 15:24:21 apolo volumio[1008]: info: Discovery: Getting this device information Feb 23 15:24:21 apolo volumio[1008]: info: CoreCommandRouter::volumioGetState Feb 23 15:24:21 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 15:24:21 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 23 15:24:21 apolo volumio[1008]: info: Received Get System Info Feb 23 15:24:21 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 15:24:21 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 15:24:21 apolo volumio[1008]: info: Discovery: Getting this device information Feb 23 15:24:21 apolo volumio[1008]: info: CoreCommandRouter::volumioGetState Feb 23 15:24:21 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 15:24:21 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 23 15:24:21 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 23 15:24:24 apolo go-librespot[16212]: time="2025-02-23T15:24:24-07:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Feb 23 15:24:24 apolo volumio[1008]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify Feb 23 15:24:24 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 15:24:24 apolo volumio[1008]: info: Disabling plugin spop Feb 23 15:24:24 apolo volumio[1008]: info: Done. Feb 23 15:24:24 apolo volumio[1008]: info: Connection to go-librespot Websocket closed Feb 23 15:24:24 apolo sudo[21205]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop go-librespot-daemon.service Feb 23 15:24:24 apolo sudo[21205]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 23 15:24:24 apolo systemd[1]: Stopping go-librespot Daemon... Feb 23 15:24:24 apolo systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Feb 23 15:24:24 apolo systemd[1]: go-librespot-daemon.service: Succeeded. Feb 23 15:24:24 apolo systemd[1]: Stopped go-librespot Daemon. Feb 23 15:24:24 apolo volumio[1008]: (node:1008) UnhandledPromiseRejectionWarning: Error: socket hang up Feb 23 15:24:24 apolo volumio[1008]: at connResetException (internal/errors.js:607:14) Feb 23 15:24:24 apolo volumio[1008]: at Socket.socketOnEnd (_http_client.js:493:23) Feb 23 15:24:24 apolo volumio[1008]: at Socket.emit (events.js:327:22) Feb 23 15:24:24 apolo volumio[1008]: at endReadableNT (internal/streams/readable.js:1327:12) Feb 23 15:24:24 apolo volumio[1008]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Feb 23 15:24:24 apolo volumio[1008]: (Use `node --trace-warnings ...` to show where the warning was created) Feb 23 15:24:24 apolo volumio[1008]: (node:1008) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 1) Feb 23 15:24:24 apolo volumio[1008]: (node:1008) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code. Feb 23 15:24:24 apolo sudo[21205]: pam_unix(sudo:session): session closed for user root Feb 23 15:24:25 apolo volumio[1008]: info: Enabling plugin volspotconnect2 Feb 23 15:24:25 apolo volumio[1008]: info: Loading plugin "volspotconnect2"... Feb 23 15:24:25 apolo volumio[1008]: info: PLUGIN START: volspotconnect2 Feb 23 15:24:26 apolo volumio[1008]: [SpotifyConnect] Creating VLS config file Feb 23 15:24:26 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 15:24:26 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 15:24:26 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 15:24:26 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 15:24:26 apolo volumio[1008]: [SpotifyConnect] Volumio alsa_controller configuration: Feb 23 15:24:26 apolo volumio[1008]: outdev:volumio Feb 23 15:24:26 apolo volumio[1008]: outputdevicemixer:2 Feb 23 15:24:26 apolo volumio[1008]: volcurve:logarithmic Feb 23 15:24:26 apolo volumio[1008]: mixtype:Hardware Feb 23 15:24:26 apolo volumio[1008]: mixname:Digital Feb 23 15:24:26 apolo volumio[1008]: Feb 23 15:24:26 apolo volumio[1008]: [SpotifyConnect] MODULAR_ALSA_PIPELINE: true Feb 23 15:24:26 apolo volumio[1008]: [SpotifyConnect] Feb 23 15:24:26 apolo volumio[1008]: outdev:volumio Feb 23 15:24:26 apolo volumio[1008]: mixer:alsa Feb 23 15:24:26 apolo volumio[1008]: mixname:Digital Feb 23 15:24:26 apolo volumio[1008]: mixdev:hw:2 Feb 23 15:24:26 apolo volumio[1008]: mixidx:0 Feb 23 15:24:26 apolo volumio[1008]: Feb 23 15:24:26 apolo volumio[1008]: [SpotifyConnect] Starting metadata listener Feb 23 15:24:26 apolo sudo[21216]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volspotconnect2.service Feb 23 15:24:26 apolo sudo[21216]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 23 15:24:26 apolo systemd[1]: Started Volspotconnect2 Daemon. Feb 23 15:24:26 apolo sudo[21216]: pam_unix(sudo:session): session closed for user root Feb 23 15:24:26 apolo volumio[1008]: [SpotifyConnect] Vollibrespot Daemon service started! Feb 23 15:24:26 apolo volumio[21218]: vollibrespot v0.2.2 cd96399 2020-10-07 (librespot 08d8bcc 2020-10-07) -- Built On 2020-10-07 Feb 23 15:24:26 apolo volumio[21218]: Reading Config from "volspotify.toml" Feb 23 15:24:26 apolo volumio[21218]: [Vollibrespot] : Using Alsa backend with device: volumio Feb 23 15:24:26 apolo volumio[1008]: [Metrics] SpotifyConnect: 0s 146.87ms Feb 23 15:24:26 apolo volumio[1008]: info: Done. Feb 23 15:24:26 apolo volumio[21218]: [Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Other, message: "No such device" } Feb 23 15:24:26 apolo volumio[1008]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 23 15:24:26 apolo volumio[1008]: [SpotifyConnect] config : toggling initvol/volume_ctrl Feb 23 15:24:29 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Feb 23 15:24:35 apolo volumio[1008]: info: CALLMETHOD: music_service volspotconnect2 saveVolspotconnectAccount [object Object] Feb 23 15:24:35 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: volspotconnect2 , saveVolspotconnectAccount Feb 23 15:24:35 apolo volumio[1008]: [SpotifyConnect] Creating VLS config file Feb 23 15:24:35 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 15:24:35 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 15:24:35 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 15:24:35 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 15:24:35 apolo volumio[1008]: [SpotifyConnect] Volumio alsa_controller configuration: Feb 23 15:24:35 apolo volumio[1008]: outdev:volumio Feb 23 15:24:35 apolo volumio[1008]: outputdevicemixer:2 Feb 23 15:24:35 apolo volumio[1008]: volcurve:logarithmic Feb 23 15:24:35 apolo volumio[1008]: mixtype:Hardware Feb 23 15:24:35 apolo volumio[1008]: mixname:Digital Feb 23 15:24:35 apolo volumio[1008]: Feb 23 15:24:35 apolo volumio[1008]: [SpotifyConnect] MODULAR_ALSA_PIPELINE: true Feb 23 15:24:35 apolo volumio[1008]: [SpotifyConnect] Feb 23 15:24:35 apolo volumio[1008]: outdev:volumio Feb 23 15:24:35 apolo volumio[1008]: mixer:alsa Feb 23 15:24:35 apolo volumio[1008]: mixname:Digital Feb 23 15:24:35 apolo volumio[1008]: mixdev:hw:2 Feb 23 15:24:35 apolo volumio[1008]: mixidx:0 Feb 23 15:24:35 apolo volumio[1008]: Feb 23 15:24:35 apolo volumio[1008]: [SpotifyConnect] Restarting Vollibrespot Daemon Feb 23 15:24:35 apolo sudo[21298]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volspotconnect2.service Feb 23 15:24:35 apolo sudo[21298]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 23 15:24:35 apolo systemd[1]: Stopping Volspotconnect2 Daemon... Feb 23 15:24:35 apolo systemd[1]: volspotconnect2.service: Main process exited, code=killed, status=15/TERM Feb 23 15:24:35 apolo systemd[1]: volspotconnect2.service: Succeeded. Feb 23 15:24:35 apolo systemd[1]: Stopped Volspotconnect2 Daemon. Feb 23 15:24:35 apolo systemd[1]: Started Volspotconnect2 Daemon. Feb 23 15:24:35 apolo sudo[21298]: pam_unix(sudo:session): session closed for user root Feb 23 15:24:35 apolo volumio[1008]: [SpotifyConnect] Vollibrespot Daemon service restarted! Feb 23 15:24:35 apolo volumio[21300]: vollibrespot v0.2.2 cd96399 2020-10-07 (librespot 08d8bcc 2020-10-07) -- Built On 2020-10-07 Feb 23 15:24:35 apolo volumio[21300]: Reading Config from "volspotify.toml" Feb 23 15:24:35 apolo volumio[21300]: [Vollibrespot] : Using Alsa backend with device: volumio Feb 23 15:24:35 apolo volumio[21300]: [Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Other, message: "No such device" } Feb 23 15:24:38 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 23 15:24:39 apolo volumio[1008]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Feb 23 15:24:39 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Feb 23 15:24:39 apolo volumio[1008]: info: Received Get System Version Feb 23 15:24:39 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 15:24:39 apolo volumio[1008]: info: Received Get System Info Feb 23 15:24:39 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 15:24:39 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 15:24:39 apolo volumio[1008]: info: Discovery: Getting this device information Feb 23 15:24:39 apolo volumio[1008]: info: CoreCommandRouter::volumioGetState Feb 23 15:24:39 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 15:24:51 apolo volumio[21300]: [Vollibrespot] : Connecting to AP "ap-guc3.spotify.com:443" Feb 23 15:24:51 apolo volumio[21300]: [Vollibrespot] : Authenticated as "aberlanga25" ! Feb 23 15:24:51 apolo volumio[21300]: [Vollibrespot] : Setting up new mixer: card:hw:2 mixer:Digital index:0 Feb 23 15:24:51 apolo volumio[21300]: [Vollibrespot] : Alsa Mixer info min: 0 (MilliBel(-9999999)[dB]) -- max: 207 (MilliBel(0)[dB]) HW: true Feb 23 15:24:51 apolo volumio[21300]: [Vollibrespot] : Using alsa sink Feb 23 15:24:51 apolo volumio[21300]: [Vollibrespot] : Metadata pipe established Feb 23 15:24:51 apolo volumio[21300]: [Vollibrespot] : Country: "US" Feb 23 15:24:51 apolo volumio[21300]: [Vollibrespot] : Event: Volume { volume_to_mixer: 26214 } Feb 23 15:24:51 apolo volumio[1008]: [SpotifyConnect] 40 Feb 23 15:24:51 apolo volumio[1008]: [SpotifyConnect] Volume: Spotify:40 Volumio: 40 Feb 23 15:24:51 apolo volumio[1008]: info: CoreStateMachine::pushState Feb 23 15:24:51 apolo volumio[1008]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 15:24:51 apolo volumio[1008]: info: CoreCommandRouter::volumioPushState Feb 23 15:24:52 apolo volumio[21300]: [Vollibrespot] : Fetching autoplay context uri Feb 23 15:24:52 apolo volumio[21300]: [Vollibrespot] : Event: SessionActive { became_active_at: 1740349492225 } Feb 23 15:24:52 apolo volumio[21300]: [Vollibrespot] : SessionActive! Feb 23 15:24:52 apolo volumio[21300]: [Vollibrespot] : Event: PlaybackStarted { track_id: SpotifyId { id: 328365636848399653536088036914971512062, audio_type: Track } } Feb 23 15:24:52 apolo volumio[21300]: [Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 328365636848399653536088036914971512062, audio_type: Track } } Feb 23 15:24:52 apolo volumio[1008]: [SpotifyConnect] A connect session has begun Feb 23 15:24:52 apolo volumio[1008]: [SpotifyConnect] Device palyback is active! Feb 23 15:24:52 apolo volumio[1008]: info: CoreCommandRouter::volumioGetState Feb 23 15:24:52 apolo volumio[1008]: [SpotifyConnect] Currently active: spop Feb 23 15:24:52 apolo volumio[1008]: [SpotifyConnect] Stopping currently active service Feb 23 15:24:52 apolo volumio[1008]: info: CoreCommandRouter::volumioStop Feb 23 15:24:52 apolo volumio[1008]: info: CoreStateMachine::stop Feb 23 15:24:52 apolo volumio[1008]: info: CoreStateMachine::serviceStop Feb 23 15:24:52 apolo volumio[1008]: info: CoreCommandRouter::serviceStop Feb 23 15:24:52 apolo volumio[1008]: error: WARNING: No stop method for service spop Feb 23 15:24:52 apolo volumio[1008]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 15:24:52 apolo volumio[1008]: TypeError: Cannot read property 'then' of undefined Feb 23 15:24:52 apolo volumio[1008]: at SpotConnEvents. (/data/plugins/music_service/volspotconnect2/index.js:145:23) Feb 23 15:24:52 apolo volumio[1008]: at SpotConnEvents.emit (events.js:315:20) Feb 23 15:24:52 apolo volumio[1008]: at SpotConnEvents.parseData (/data/plugins/music_service/volspotconnect2/SpotConnController.js:73:16) Feb 23 15:24:52 apolo volumio[1008]: at Socket. (/data/plugins/music_service/volspotconnect2/SpotConnController.js:15:12) Feb 23 15:24:52 apolo volumio[1008]: at Socket.emit (events.js:315:20) Feb 23 15:24:52 apolo volumio[1008]: at UDP.onMessage [as onmessage] (dgram.js:919:8) Feb 23 15:24:52 apolo volumio[1008]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 15:24:52 apolo volumio[21300]: [Vollibrespot] : Autoplay uri resolved to <"spotify:station:playlist:7FEC3iNVGftXSLnHc0yFW5"> Feb 23 15:24:52 apolo volumio[21300]: [Vollibrespot] : Resolving uri "spotify:station:playlist:7FEC3iNVGftXSLnHc0yFW5" Feb 23 15:24:52 apolo volumio[21300]: [Vollibrespot] : Event: GotToken { token: Token { access_token: "BQAOTBdJI-ZAJv16PMJCn-xGyAbuuV-kxJf4RbR6TcjexgvJVdx9RZpOnjIr-gJrkCE79hcEjU2O7RLbn5xJPArqMxcrh360MhMlWgGUjsm6r0GM7GCLsdx0Uer5DZ4UQIuqYovXxOaoTWFe8xhhpPuYr6bM_xIrMfvA174Jr6Ki9KTawSHqO3bN7oaEbZjNcFWBYffKnKXcf5P_4wb3cxvb02SfsU2Y4Vukg_0", expires_in: 3600, token_type: "Bearer", scope: ["streaming", "user-read-playback-state", "user-modify-playback-state", "user-read-currently-playing", "user-read-private"] } } Feb 23 15:24:52 apolo volumio[21300]: [Vollibrespot] : Loading with Spotify URI Feb 23 15:24:52 apolo volumio[21300]: [Vollibrespot] : Resolved 50 tracks from <"spotify:playlist:7FEC3iNVGftXSLnHc0yFW5"> Feb 23 15:24:52 apolo sudo[21443]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-02-23 15:23 Feb 23 15:24:52 apolo sudo[21443]: 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="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"