Dec 18 17:33:07 volumio-barn systemd[1]: Stopping user@1000.service - User Manager for UID 1000...
Dec 18 17:33:07 volumio-barn systemd[2578]: Activating special unit exit.target...
Dec 18 17:33:07 volumio-barn systemd[2578]: Stopped target default.target - Main User Target.
Dec 18 17:33:07 volumio-barn systemd[2578]: Stopping mpris-proxy.service - Bluetooth mpris proxy...
Dec 18 17:33:07 volumio-barn mpris-proxy[2609]: org.bluez appeared
Dec 18 17:33:07 volumio-barn mpris-proxy[2609]: Bluetooth Adapter /org/bluez/hci0 found
Dec 18 17:33:07 volumio-barn mpris-proxy[2609]: Bluetooth Adapter /org/bluez/hci0 removed
Dec 18 17:33:07 volumio-barn mpris-proxy[2609]: org.bluez disappeared
Dec 18 17:33:07 volumio-barn systemd[2578]: Stopped mpris-proxy.service - Bluetooth mpris proxy.
Dec 18 17:33:07 volumio-barn systemd[2578]: Stopping dbus.service - D-Bus User Message Bus...
Dec 18 17:33:07 volumio-barn systemd[2578]: Stopped dbus.service - D-Bus User Message Bus.
Dec 18 17:33:07 volumio-barn systemd[2578]: Removed slice session.slice - User Core Session Slice.
Dec 18 17:33:07 volumio-barn systemd[2578]: Stopped target basic.target - Basic System.
Dec 18 17:33:07 volumio-barn systemd[2578]: Stopped target paths.target - Paths.
Dec 18 17:33:07 volumio-barn systemd[2578]: Stopped target sockets.target - Sockets.
Dec 18 17:33:07 volumio-barn systemd[2578]: Stopped target timers.target - Timers.
Dec 18 17:33:07 volumio-barn systemd[2578]: Closed dbus.socket - D-Bus User Message Bus Socket.
Dec 18 17:33:07 volumio-barn systemd[2578]: Closed dirmngr.socket - GnuPG network certificate management daemon.
Dec 18 17:33:07 volumio-barn systemd[2578]: Closed gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers).
Dec 18 17:33:07 volumio-barn systemd[2578]: Closed gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted).
Dec 18 17:33:07 volumio-barn systemd[2578]: Closed gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation).
Dec 18 17:33:07 volumio-barn systemd[2578]: Closed gpg-agent.socket - GnuPG cryptographic agent and passphrase cache.
Dec 18 17:33:07 volumio-barn systemd[2578]: Removed slice app.slice - User Application Slice.
Dec 18 17:33:07 volumio-barn systemd[2578]: Reached target shutdown.target - Shutdown.
Dec 18 17:33:07 volumio-barn systemd[2578]: Finished systemd-exit.service - Exit the Session.
Dec 18 17:33:07 volumio-barn systemd[2578]: Reached target exit.target - Exit the Session.
Dec 18 17:33:07 volumio-barn systemd[1]: user@1000.service: Deactivated successfully.
Dec 18 17:33:07 volumio-barn systemd[1]: Stopped user@1000.service - User Manager for UID 1000.
Dec 18 17:33:08 volumio-barn systemd[1]: Stopping user-runtime-dir@1000.service - User Runtime Directory /run/user/1000...
Dec 18 17:33:08 volumio-barn systemd[1]: run-user-1000.mount: Deactivated successfully.
Dec 18 17:33:08 volumio-barn systemd[1]: user-runtime-dir@1000.service: Deactivated successfully.
Dec 18 17:33:08 volumio-barn systemd[1]: Stopped user-runtime-dir@1000.service - User Runtime Directory /run/user/1000.
Dec 18 17:33:08 volumio-barn systemd[1]: Removed slice user-1000.slice - User Slice of UID 1000.
Dec 18 17:33:08 volumio-barn systemd[1]: user-1000.slice: Consumed 58.761s CPU time.
Dec 18 17:33:27 volumio-barn volumio[1270]: info: Enabling plugin now_playing
Dec 18 17:33:27 volumio-barn volumio[1270]: info: Loading plugin "now_playing"...
Dec 18 17:33:28 volumio-barn volumio[1270]: info: PLUGIN START: now_playing
Dec 18 17:33:28 volumio-barn volumio[1270]: info: [now-playing] ConfigUpdater: config version unavailable. Either this is the first time the plugin is installed, or the previous version is < 0.3.0). Config will not be updated.
Dec 18 17:33:28 volumio-barn volumio[1270]: info: [now-playing] ConfigUpdater: updated config version to 1.0.3
Dec 18 17:33:28 volumio-barn volumio[1270]: info: [now-playing] App is listening on port 4004.
Dec 18 17:33:28 volumio-barn volumio[1270]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds
Dec 18 17:33:28 volumio-barn volumio[1270]: info: Done.
Dec 18 17:33:42 volumio-barn volumio[1270]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/soundcloud/volumio/bookworm/armhf
Dec 18 17:33:44 volumio-barn volumio[1270]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/soundcloud/volumio/bookworm/armhf
Dec 18 17:33:44 volumio-barn volumio[1270]: info: Folder /tmp/plugins removed
Dec 18 17:33:44 volumio-barn volumio[1270]: info: Check plugin dependencies
Dec 18 17:33:44 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 18 17:33:44 volumio-barn volumio[1270]: info: Checking if plugin already exists
Dec 18 17:33:44 volumio-barn volumio[1270]: info: Rename folder
Dec 18 17:33:44 volumio-barn volumio[1270]: info: Folder /tmp/downloaded_plugin.zip removed
Dec 18 17:33:44 volumio-barn volumio[1270]: info: Move to category
Dec 18 17:33:44 volumio-barn volumio[1270]: info: Checking if install.sh is present
Dec 18 17:33:44 volumio-barn volumio[1270]: info: Executing install.sh
Dec 18 17:33:44 volumio-barn sudo[2882]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/music_service/soundcloud/install.sh
Dec 18 17:33:44 volumio-barn sudo[2882]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 18 17:33:44 volumio-barn sudo[2882]: pam_unix(sudo:session): session closed for user root
Dec 18 17:33:44 volumio-barn volumio[1270]: info: SoundCloud plugin installed
Dec 18 17:33:44 volumio-barn volumio[1270]: Plugin install end detected on script
Dec 18 17:33:44 volumio-barn volumio[1270]: info: Install script completed
Dec 18 17:33:44 volumio-barn volumio[1270]: info: Adding reference to registry
Dec 18 17:33:44 volumio-barn volumio[1270]: info: Done installing plugin.
Dec 18 17:33:44 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Dec 18 17:33:44 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Dec 18 17:33:44 volumio-barn volumio[1270]: info: Folder /tmp/plugins removed
Dec 18 17:33:44 volumio-barn volumio[1270]: info: Folder /tmp/downloaded_plugin.zip removed
Dec 18 17:33:44 volumio-barn volumio[1270]: info: Folder /data/temp removed
Dec 18 17:33:49 volumio-barn volumio[1270]: info: Enabling plugin soundcloud
Dec 18 17:33:49 volumio-barn volumio[1270]: info: Loading plugin "soundcloud"...
Dec 18 17:33:49 volumio-barn volumio[1270]: info: PLUGIN START: soundcloud
Dec 18 17:33:49 volumio-barn volumio[1270]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 18 17:33:49 volumio-barn volumio[1270]: info: [1766097229987] CoreMusicLibrary::Adding element SoundCloud
Dec 18 17:33:49 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 18 17:33:49 volumio-barn volumio[1270]: Cannot find translation for source SoundCloud
Dec 18 17:33:49 volumio-barn volumio[1270]: info: Done.
Dec 18 17:33:59 volumio-barn volumio[1270]: info: Starting Uninstall of plugin music_service - soundcloud
Dec 18 17:33:59 volumio-barn volumio[1270]: info: Uninstalling plugin soundcloud
Dec 18 17:33:59 volumio-barn volumio[1270]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSoundCloud
Dec 18 17:33:59 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 18 17:33:59 volumio-barn volumio[1270]: info: Disabling plugin soundcloud
Dec 18 17:33:59 volumio-barn volumio[1270]: info: Checking if uninstall.sh is present
Dec 18 17:33:59 volumio-barn volumio[1270]: info: Executing uninstall.sh
Dec 18 17:33:59 volumio-barn sudo[2975]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/music_service/soundcloud/uninstall.sh
Dec 18 17:33:59 volumio-barn sudo[2975]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 18 17:33:59 volumio-barn sudo[2975]: pam_unix(sudo:session): session closed for user root
Dec 18 17:33:59 volumio-barn volumio[1270]: info: Uninstall script completed
Dec 18 17:33:59 volumio-barn volumio[1270]: info: Removing plugin soundcloud from configuration
Dec 18 17:33:59 volumio-barn volumio[1270]: info: Successfully removed soundcloud configuration files
Dec 18 17:33:59 volumio-barn volumio[1270]: info: Plugin folders cleanup
Dec 18 17:33:59 volumio-barn volumio[1270]: info: Scanning into folder /volumio/app/plugins/
Dec 18 17:33:59 volumio-barn volumio[1270]: info: Scanning category audio_interface
Dec 18 17:33:59 volumio-barn volumio[1270]: info: Scanning category miscellanea
Dec 18 17:33:59 volumio-barn volumio[1270]: info: Scanning category music_service
Dec 18 17:33:59 volumio-barn volumio[1270]: info: Scanning category plugins.json
Dec 18 17:33:59 volumio-barn volumio[1270]: info: Scanning category system_controller
Dec 18 17:33:59 volumio-barn volumio[1270]: info: Scanning category user_interface
Dec 18 17:33:59 volumio-barn volumio[1270]: info: Scanning into folder /data/plugins/
Dec 18 17:33:59 volumio-barn volumio[1270]: info: Scanning category music_service
Dec 18 17:33:59 volumio-barn volumio[1270]: info: Cleaning folder for soundcloud
Dec 18 17:33:59 volumio-barn volumio[1270]: info: Scanning category user_interface
Dec 18 17:33:59 volumio-barn volumio[1270]: info: Plugin folders cleanup completed
Dec 18 17:33:59 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Dec 18 17:33:59 volumio-barn volumio[1270]: info: [{"prettyName":"Now Playing","name":"now_playing","category":"user_interface","version":"1.0.3","icon":"fa-play-circle","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Touch Display","name":"touch_display","category":"user_interface","version":"3.6.0","icon":"fa-hand-pointer-o","isManuallyInstalled":false,"enabled":true,"active":true}]
Dec 18 17:33:59 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Dec 18 17:34:11 volumio-barn volumio[1270]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/bookworm/armhf
Dec 18 17:34:13 volumio-barn volumio[1270]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/bookworm/armhf
Dec 18 17:34:13 volumio-barn volumio[1270]: info: Folder /tmp/plugins removed
Dec 18 17:34:14 volumio-barn volumio[1270]: info: Check plugin dependencies
Dec 18 17:34:14 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Dec 18 17:34:14 volumio-barn volumio[1270]: info: Checking if plugin already exists
Dec 18 17:34:14 volumio-barn volumio[1270]: info: Rename folder
Dec 18 17:34:14 volumio-barn volumio[1270]: info: Folder /tmp/downloaded_plugin.zip removed
Dec 18 17:34:14 volumio-barn volumio[1270]: info: Move to category
Dec 18 17:34:15 volumio-barn volumio[1270]: info: Checking if install.sh is present
Dec 18 17:34:15 volumio-barn volumio[1270]: info: Executing install.sh
Dec 18 17:34:15 volumio-barn sudo[3055]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/music_service/spop/install.sh
Dec 18 17:34:15 volumio-barn sudo[3055]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 18 17:34:15 volumio-barn volumio[1270]: info: Installing Go-librespot
Dec 18 17:34:15 volumio-barn volumio[1270]: info: Checking old vollibrespot installs
Dec 18 17:34:15 volumio-barn systemd[1]: Reloading.
Dec 18 17:34:16 volumio-barn volumio[1270]: info: Downloading daemon
Dec 18 17:34:22 volumio-barn volumio[1270]: info: Creating directories
Dec 18 17:34:22 volumio-barn volumio[1270]: info: Creating data directory
Dec 18 17:34:22 volumio-barn volumio[1270]: info: Creating Start Script
Dec 18 17:34:22 volumio-barn systemd[1]: Reloading.
Dec 18 17:34:23 volumio-barn sudo[3055]: pam_unix(sudo:session): session closed for user root
Dec 18 17:34:23 volumio-barn volumio[1270]: Plugin install end detected on script
Dec 18 17:34:23 volumio-barn volumio[1270]: info: Install script completed
Dec 18 17:34:23 volumio-barn volumio[1270]: info: Adding reference to registry
Dec 18 17:34:23 volumio-barn volumio[1270]: info: Done installing plugin.
Dec 18 17:34:23 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Dec 18 17:34:23 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Dec 18 17:34:23 volumio-barn volumio[1270]: info: Folder /tmp/plugins removed
Dec 18 17:34:23 volumio-barn volumio[1270]: info: Folder /tmp/downloaded_plugin.zip removed
Dec 18 17:34:23 volumio-barn volumio[1270]: info: Folder /data/temp removed
Dec 18 17:34:26 volumio-barn volumio[1270]: info: Enabling plugin spop
Dec 18 17:34:26 volumio-barn volumio[1270]: info: Loading plugin "spop"...
Dec 18 17:34:27 volumio-barn volumio[1270]: info: PLUGIN START: spop
Dec 18 17:34:27 volumio-barn volumio[1270]: info: Creating Spotify config file
Dec 18 17:34:27 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 18 17:34:27 volumio-barn volumio[1270]: info: Done.
Dec 18 17:34:27 volumio-barn volumio[1270]: info: Spotify config file written
Dec 18 17:34:27 volumio-barn volumio[1270]: info: No need to fix Spotify hosts
Dec 18 17:34:27 volumio-barn sudo[3137]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Dec 18 17:34:27 volumio-barn sudo[3137]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 18 17:34:27 volumio-barn systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Dec 18 17:34:27 volumio-barn systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Dec 18 17:34:27 volumio-barn systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 18 17:34:27 volumio-barn go-librespot[3139]: go-librespot daemon starting...
Dec 18 17:34:27 volumio-barn sudo[3137]: pam_unix(sudo:session): session closed for user root
Dec 18 17:34:27 volumio-barn go-librespot[3140]: time="2025-12-18T17:34:27-05:00" level=info msg="running go-librespot 0.4.0"
Dec 18 17:34:27 volumio-barn go-librespot[3140]: time="2025-12-18T17:34:27-05:00" level=debug msg="no app state found"
Dec 18 17:34:27 volumio-barn go-librespot[3140]: time="2025-12-18T17:34:27-05:00" level=debug msg="stored credentials not found"
Dec 18 17:34:27 volumio-barn go-librespot[3140]: time="2025-12-18T17:34:27-05:00" level=info msg="generated new device id: efb0d973b1968c54e8600ee91e891bd7cfe457cb"
Dec 18 17:34:27 volumio-barn go-librespot[3140]: time="2025-12-18T17:34:27-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 18 17:34:27 volumio-barn go-librespot[3140]: time="2025-12-18T17:34:27-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 18 17:34:27 volumio-barn go-librespot[3140]: time="2025-12-18T17:34:27-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 18 17:34:27 volumio-barn go-librespot[3140]: time="2025-12-18T17:34:27-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 18 17:34:27 volumio-barn go-librespot[3140]: time="2025-12-18T17:34:27-05:00" level=info msg="zeroconf server listening on port 41333"
Dec 18 17:34:30 volumio-barn volumio[1270]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 18 17:34:30 volumio-barn volumio[1270]: info: go-librespot daemon successfully initialized
Dec 18 17:34:33 volumio-barn volumio[1270]: info: Initializing connection to go-librespot Websocket
Dec 18 17:34:33 volumio-barn go-librespot[3140]: time="2025-12-18T17:34:33-05:00" level=debug msg="new websocket client"
Dec 18 17:34:33 volumio-barn volumio[1270]: info: Connection to go-librespot Websocket established
Dec 18 17:34:34 volumio-barn volumio[1270]: info: Received OAUTH Data
Dec 18 17:34:34 volumio-barn volumio[1270]: info: Executing Spotify Oauth Login
Dec 18 17:34:34 volumio-barn volumio[1270]: info: Saving Spotify Refresh Token
Dec 18 17:34:34 volumio-barn volumio[1270]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Dec 18 17:34:34 volumio-barn volumio[1270]: SPOTIFY: BQCWvaHbDkqEkeokfXQFGJc-Hik49WXtk2Z7WE6aSpLYCr-kFZqVcjktXNnOXM_Wk_XtA1hZWgz7L8-t-ZdznlOtcRJI8D1urBExHprZOk5yfN-5NssMMnJboVi7PnCHpqa-3W10lsPDG1q71wtPDD1ZIdp6WZ8FnuB-7SWuSfSrPUaQ4gUOBItbYO1znYBt944ux-I8UJtiR-2VlaRkWsuAHNC7YymZZ0sfGyuXcelWRR1fdWNzofF3Ww6O4mgbksJgVbIf4zL3s1Jir1_uaiNqI3DtxPHQ8n-l-ZHeTmpQNk1TRVIbGVYQNm4G
Dec 18 17:34:34 volumio-barn volumio[1270]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Dec 18 17:34:34 volumio-barn volumio[1270]: info: New Spotify access token = BQCWvaHbDkqEkeokfXQFGJc-Hik49WXtk2Z7WE6aSpLYCr-kFZqVcjktXNnOXM_Wk_XtA1hZWgz7L8-t-ZdznlOtcRJI8D1urBExHprZOk5yfN-5NssMMnJboVi7PnCHpqa-3W10lsPDG1q71wtPDD1ZIdp6WZ8FnuB-7SWuSfSrPUaQ4gUOBItbYO1znYBt944ux-I8UJtiR-2VlaRkWsuAHNC7YymZZ0sfGyuXcelWRR1fdWNzofF3Ww6O4mgbksJgVbIf4zL3s1Jir1_uaiNqI3DtxPHQ8n-l-ZHeTmpQNk1TRVIbGVYQNm4G
Dec 18 17:34:34 volumio-barn volumio[1270]: info: Spotify credentials grant success - running version from March 24, 2019
Dec 18 17:34:35 volumio-barn sudo[3163]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Dec 18 17:34:35 volumio-barn sudo[3163]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 18 17:34:35 volumio-barn sudo[3163]: pam_unix(sudo:session): session closed for user root
Dec 18 17:34:35 volumio-barn sudo[3165]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Dec 18 17:34:35 volumio-barn sudo[3165]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 18 17:34:35 volumio-barn sudo[3165]: pam_unix(sudo:session): session closed for user root
Dec 18 17:34:35 volumio-barn volumio[1270]: verbose: New Socket.io Connection to 192.168.1.228 from 192.168.1.215 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9
Dec 18 17:34:35 volumio-barn volumio[1270]: SPOTIFY: User informations: {"country":"US","display_name":"Rainer Guttkuhn","email":"rguttkuhn@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31t44d5scnxm2w5rngt2s4oovf5e"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31t44d5scnxm2w5rngt2s4oovf5e","id":"31t44d5scnxm2w5rngt2s4oovf5e","images":[],"product":"premium","type":"user","uri":"spotify:user:31t44d5scnxm2w5rngt2s4oovf5e"}
Dec 18 17:34:35 volumio-barn volumio[1270]: info: Creating Spotify config file
Dec 18 17:34:35 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 18 17:34:35 volumio-barn volumio[1270]: info: Spotify config file written
Dec 18 17:34:35 volumio-barn sudo[3169]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Dec 18 17:34:35 volumio-barn sudo[3169]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 18 17:34:35 volumio-barn systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon...
Dec 18 17:34:35 volumio-barn systemd[1]: go-librespot-daemon.service: Deactivated successfully.
Dec 18 17:34:35 volumio-barn volumio[1270]: info: Connection to go-librespot Websocket closed
Dec 18 17:34:35 volumio-barn systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 18 17:34:35 volumio-barn systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 18 17:34:35 volumio-barn sudo[3169]: pam_unix(sudo:session): session closed for user root
Dec 18 17:34:35 volumio-barn go-librespot[3172]: go-librespot daemon starting...
Dec 18 17:34:35 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:35-05:00" level=info msg="running go-librespot 0.4.0"
Dec 18 17:34:35 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:35-05:00" level=debug msg="app state loaded"
Dec 18 17:34:35 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:35-05:00" level=debug msg="stored credentials not found"
Dec 18 17:34:35 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:35-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 18 17:34:35 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Dec 18 17:34:35 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache
Dec 18 17:34:35 volumio-barn volumio[1270]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Dec 18 17:34:35 volumio-barn volumio[1270]: SPOTIFY: BQBSuGqm-OVTfxOmmJ1rTzvvi3a49mBQEI6pVvuuAHlI6iMXmenfKLBnPbhH1j9xY4vk4u38bsc5HeAAGlAYRb8erpwHX3JXuOPPuy_hqWrDIoyt0MmiS4a7CK8hpr4VED9BlGtyYUKUpzf25tmx3yRccrzUDhaYlvEj6FRhtO-pcXchk_NJrxr-deVCfDX0-thSccvVBvKe8pUHg7CditqAxcTsovSfVOWs0AeBPvYlfpD1HwcKE_J-oJN52669sym375hNeBbW0KbCvutAyVmrHQ8K3MTeb0nYfpltPTCW_1K0d7HGtSJ6EjgI
Dec 18 17:34:35 volumio-barn volumio[1270]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Dec 18 17:34:35 volumio-barn volumio[1270]: info: New Spotify access token = BQBSuGqm-OVTfxOmmJ1rTzvvi3a49mBQEI6pVvuuAHlI6iMXmenfKLBnPbhH1j9xY4vk4u38bsc5HeAAGlAYRb8erpwHX3JXuOPPuy_hqWrDIoyt0MmiS4a7CK8hpr4VED9BlGtyYUKUpzf25tmx3yRccrzUDhaYlvEj6FRhtO-pcXchk_NJrxr-deVCfDX0-thSccvVBvKe8pUHg7CditqAxcTsovSfVOWs0AeBPvYlfpD1HwcKE_J-oJN52669sym375hNeBbW0KbCvutAyVmrHQ8K3MTeb0nYfpltPTCW_1K0d7HGtSJ6EjgI
Dec 18 17:34:35 volumio-barn volumio[1270]: info: Spotify credentials grant success - running version from March 24, 2019
Dec 18 17:34:35 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:35-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 18 17:34:35 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:35-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 18 17:34:35 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:35-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 18 17:34:35 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:35-05:00" level=info msg="zeroconf server listening on port 37903"
Dec 18 17:34:35 volumio-barn volumio[1270]: info: CoreCommandRouter::volumioGetVisibleSources
Dec 18 17:34:35 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 18 17:34:35 volumio-barn volumio[1270]: info: CoreCommandRouter::volumioGetState
Dec 18 17:34:35 volumio-barn volumio[1270]: info: CorePlayQueue::getTrack 0
Dec 18 17:34:35 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Dec 18 17:34:35 volumio-barn volumio[1270]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 18 17:34:35 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Dec 18 17:34:35 volumio-barn volumio[1270]: info: Received Get System Info
Dec 18 17:34:35 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Dec 18 17:34:35 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Dec 18 17:34:35 volumio-barn volumio[1270]: info: Discovery: Getting this device information
Dec 18 17:34:35 volumio-barn volumio[1270]: info: CoreCommandRouter::volumioGetState
Dec 18 17:34:35 volumio-barn volumio[1270]: info: CorePlayQueue::getTrack 0
Dec 18 17:34:35 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Dec 18 17:34:35 volumio-barn volumio[1270]: info: CoreCommandRouter::volumioGetState
Dec 18 17:34:35 volumio-barn volumio[1270]: info: CorePlayQueue::getTrack 0
Dec 18 17:34:35 volumio-barn volumio[1270]: info: Listing playlists
Dec 18 17:34:35 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
Dec 18 17:34:35 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Dec 18 17:34:35 volumio-barn volumio[1270]: SPOTIFY: User informations: {"country":"US","display_name":"Rainer Guttkuhn","email":"rguttkuhn@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31t44d5scnxm2w5rngt2s4oovf5e"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31t44d5scnxm2w5rngt2s4oovf5e","id":"31t44d5scnxm2w5rngt2s4oovf5e","images":[],"product":"premium","type":"user","uri":"spotify:user:31t44d5scnxm2w5rngt2s4oovf5e"}
Dec 18 17:34:35 volumio-barn volumio[1270]: info: Spotify Successfully logged in
Dec 18 17:34:35 volumio-barn volumio[1270]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 18 17:34:35 volumio-barn volumio[1270]: info: [1766097275705] CoreMusicLibrary::Adding element Spotify
Dec 18 17:34:35 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 18 17:34:35 volumio-barn volumio[1270]: Cannot find translation for source Spotify
Dec 18 17:34:35 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:35-05:00" level=debug msg="obtained new client token: AAAQgDAjcRBclbDBQyECNKnq/Y6NXO32V2ULR77MTnCskNIfXgMo3qwktcD3kkrPi+ggudakKoBzou9QWdJEJ4vowwFMra23X09J8eOd403+Vxc6i5nT56N7iYjMg7asXD3jTc7t9ho+v3UZZIHjf8JcWRoy1w9eGtzoloTFQmUX8mjJwYldZbH29GFd0eW4XR/zmFU9jZAen9Ic5mznX+dskG4RxtvvL2XgygA06Hq9kZGC33C+HL79RQ=="
Dec 18 17:34:35 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:35-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 18 17:34:35 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:35-05:00" level=debug msg="completed keyexchange"
Dec 18 17:34:35 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:35-05:00" level=debug msg="completed challenge"
Dec 18 17:34:35 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:35-05:00" level=info msg="authenticated AP" username="31************************5e"
Dec 18 17:34:36 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:36-05:00" level=info msg="authenticated Login5" username="31************************5e"
Dec 18 17:34:36 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:36-05:00" level=debug msg="stored credentials" username="31************************5e"
Dec 18 17:34:36 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:36-05:00" level=debug msg="initializing zeroconf session" username="31************************5e"
Dec 18 17:34:36 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:36-05:00" level=debug msg="dealer connection opened"
Dec 18 17:34:36 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:36-05:00" level=trace msg="starting accesspoint recv loop"
Dec 18 17:34:36 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:36-05:00" level=trace msg="starting dealer recv loop"
Dec 18 17:34:36 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:36-05:00" level=trace msg="received accesspoint ping"
Dec 18 17:34:36 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:36-05:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336"
Dec 18 17:34:36 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:36-05:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2"
Dec 18 17:34:36 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:36-05:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17"
Dec 18 17:34:36 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:36-05:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0"
Dec 18 17:34:36 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:36-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481"
Dec 18 17:34:36 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:36-05:00" level=debug msg="received connection id: MzBjOTA2MjAtYTY0...QTI1RUFBMEE2Qg=="
Dec 18 17:34:36 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:36-05:00" level=trace msg="received accesspoint pong ack"
Dec 18 17:34:36 volumio-barn volumio[1270]: info: Getting Spotify volume
Dec 18 17:34:36 volumio-barn volumio[1270]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10
Dec 18 17:34:36 volumio-barn volumio[1270]: info: CoreCommandRouter::volumioGetState
Dec 18 17:34:36 volumio-barn volumio[1270]: info: CorePlayQueue::getTrack 0
Dec 18 17:34:36 volumio-barn volumio[1270]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86
Dec 18 17:34:36 volumio-barn volumio[1270]: SPOTIFY: SPOTIFY VOLUME undefined
Dec 18 17:34:36 volumio-barn volumio[1270]: SPOTIFY: VOLUMIO VOLUME 86
Dec 18 17:34:36 volumio-barn volumio[1270]: info: Aligning Spotify Volume to Volumio Volume
Dec 18 17:34:36 volumio-barn volumio[1270]: info: CoreCommandRouter::volumioGetState
Dec 18 17:34:36 volumio-barn volumio[1270]: info: CorePlayQueue::getTrack 0
Dec 18 17:34:36 volumio-barn volumio[1270]: info: Setting Spotify Volume from Volumio: 86
Dec 18 17:34:36 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:36-05:00" level=debug msg="put connect state because NEW_DEVICE"
Dec 18 17:34:36 volumio-barn volumio[1270]: info: Spotify volume: 100
Dec 18 17:34:37 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Dec 18 17:34:37 volumio-barn volumio[1270]: info: Received Get System Info
Dec 18 17:34:37 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Dec 18 17:34:37 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Dec 18 17:34:37 volumio-barn volumio[1270]: info: Discovery: Getting this device information
Dec 18 17:34:37 volumio-barn volumio[1270]: info: CoreCommandRouter::volumioGetState
Dec 18 17:34:37 volumio-barn volumio[1270]: info: CorePlayQueue::getTrack 0
Dec 18 17:34:37 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Dec 18 17:34:37 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard
Dec 18 17:34:37 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Dec 18 17:34:37 volumio-barn volumio[1270]: info: Received Get System Info
Dec 18 17:34:37 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Dec 18 17:34:37 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Dec 18 17:34:37 volumio-barn volumio[1270]: info: Discovery: Getting this device information
Dec 18 17:34:37 volumio-barn volumio[1270]: info: CoreCommandRouter::volumioGetState
Dec 18 17:34:37 volumio-barn volumio[1270]: info: CorePlayQueue::getTrack 0
Dec 18 17:34:37 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Dec 18 17:34:37 volumio-barn volumio[1270]: SPOTIFY: SETTING SPOTIFY VOLUME 86
Dec 18 17:34:37 volumio-barn volumio[1270]: info: Sending Spotify command with payload to local API: /player/volume
Dec 18 17:34:37 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:37-05:00" level=debug msg="update volume requested to 56360/65535"
Dec 18 17:34:38 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:38-05:00" level=debug msg="put connect state because VOLUME_CHANGED"
Dec 18 17:34:38 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:38-05:00" level=trace msg="emitting websocket event: volume"
Dec 18 17:34:38 volumio-barn volumio[1270]: info: Initializing connection to go-librespot Websocket
Dec 18 17:34:38 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:38-05:00" level=debug msg="new websocket client"
Dec 18 17:34:38 volumio-barn volumio[1270]: info: Connection to go-librespot Websocket established
Dec 18 17:34:38 volumio-barn volumio[1270]: info: go-librespot daemon successfully initialized
Dec 18 17:34:41 volumio-barn volumio[1270]: info: Getting Spotify volume
Dec 18 17:34:41 volumio-barn volumio[1270]: info: Spotify volume: 86
Dec 18 17:34:41 volumio-barn volumio[1270]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11
Dec 18 17:34:41 volumio-barn volumio[1270]: info: CoreCommandRouter::volumioGetState
Dec 18 17:34:41 volumio-barn volumio[1270]: info: CorePlayQueue::getTrack 0
Dec 18 17:34:41 volumio-barn volumio[1270]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86
Dec 18 17:34:41 volumio-barn volumio[1270]: info: Initializing connection to go-librespot Websocket
Dec 18 17:34:41 volumio-barn go-librespot[3173]: time="2025-12-18T17:34:41-05:00" level=debug msg="new websocket client"
Dec 18 17:34:41 volumio-barn volumio[1270]: info: Connection to go-librespot Websocket established
Dec 18 17:34:44 volumio-barn volumio[1270]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object]
Dec 18 17:34:44 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings
Dec 18 17:34:44 volumio-barn volumio[1270]: info: Creating Spotify config file
Dec 18 17:34:44 volumio-barn volumio[1270]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 18 17:34:44 volumio-barn volumio[1270]: info: Spotify config file written
Dec 18 17:34:44 volumio-barn sudo[3196]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Dec 18 17:34:44 volumio-barn sudo[3196]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 18 17:34:44 volumio-barn systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon...
Dec 18 17:34:44 volumio-barn systemd[1]: go-librespot-daemon.service: Killing process 3177 (go-librespot) with signal SIGKILL.
Dec 18 17:34:44 volumio-barn systemd[1]: go-librespot-daemon.service: Deactivated successfully.
Dec 18 17:34:44 volumio-barn volumio[1270]: info: Connection to go-librespot Websocket closed
Dec 18 17:34:44 volumio-barn systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Dec 18 17:34:44 volumio-barn volumio[1270]: info: Connection to go-librespot Websocket closed
Dec 18 17:34:44 volumio-barn volumio[1270]: info: Getting Spotify volume
Dec 18 17:34:44 volumio-barn volumio[1270]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 18 17:34:44 volumio-barn volumio[1270]: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 18 17:34:44 volumio-barn volumio[1270]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Dec 18 17:34:44 volumio-barn volumio[1270]: errno: -111,
Dec 18 17:34:44 volumio-barn volumio[1270]: code: 'ECONNREFUSED',
Dec 18 17:34:44 volumio-barn volumio[1270]: syscall: 'connect',
Dec 18 17:34:44 volumio-barn volumio[1270]: address: '127.0.0.1',
Dec 18 17:34:44 volumio-barn volumio[1270]: port: 9879,
Dec 18 17:34:44 volumio-barn volumio[1270]: response: undefined
Dec 18 17:34:44 volumio-barn volumio[1270]: }
Dec 18 17:34:44 volumio-barn volumio[1270]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 18 17:34:44 volumio-barn systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Dec 18 17:34:44 volumio-barn go-librespot[3198]: go-librespot daemon starting...
Dec 18 17:34:44 volumio-barn sudo[3196]: pam_unix(sudo:session): session closed for user root
Dec 18 17:34:44 volumio-barn go-librespot[3210]: time="2025-12-18T17:34:44-05:00" level=info msg="running go-librespot 0.4.0"
Dec 18 17:34:44 volumio-barn go-librespot[3210]: time="2025-12-18T17:34:44-05:00" level=debug msg="app state loaded"
Dec 18 17:34:44 volumio-barn go-librespot[3210]: time="2025-12-18T17:34:44-05:00" level=info msg="api server listening on 127.0.0.1:9879"
Dec 18 17:34:44 volumio-barn go-librespot[3210]: time="2025-12-18T17:34:44-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Dec 18 17:34:44 volumio-barn go-librespot[3210]: time="2025-12-18T17:34:44-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Dec 18 17:34:44 volumio-barn go-librespot[3210]: time="2025-12-18T17:34:44-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Dec 18 17:34:44 volumio-barn go-librespot[3210]: time="2025-12-18T17:34:44-05:00" level=info msg="zeroconf server listening on port 41099"
Dec 18 17:34:44 volumio-barn go-librespot[3210]: time="2025-12-18T17:34:44-05:00" level=debug msg="obtained new client token: AABvYgI8Bfc8xrnLwiYMl2Ml1orqm5d3rFavwi3Yp2K4YlW9U7f+WDLr0jBRQcWpDMAHfeAIRCpSjTtLDjupScRWoPY2NxX3Rsl9LiWFVmBZ1DcdHp4C1eU+WdT7tDglFAr1l5m3cT8RZTO7SYd/IRGs1cBVuQQwXL6JJtsYu17lwOmzHuM7xs+XmgYIYn2M1QWKNfM3wNbtzuh/xRFEaOl9bfrwhss0Sp/2ED5rWhSD46S++4yS29IOgQ=="
Dec 18 17:34:44 volumio-barn go-librespot[3210]: time="2025-12-18T17:34:44-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070"
Dec 18 17:34:44 volumio-barn go-librespot[3210]: time="2025-12-18T17:34:44-05:00" level=debug msg="completed keyexchange"
Dec 18 17:34:44 volumio-barn sudo[3220]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-18 17:33'
Dec 18 17:34:44 volumio-barn go-librespot[3210]: time="2025-12-18T17:34:44-05:00" level=debug msg="completed challenge"
Dec 18 17:34:44 volumio-barn sudo[3220]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)"
NAME="Raspbian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
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="cfdc872d40b979cca36352a7333c940c38dc64b5"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025"
VOLUMIO_VERSION="4.073"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"