Jan 25 12:43:01 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 25 12:43:04 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 25 12:43:04 volumio volumio[1954]: info: Received Get System Info Jan 25 12:43:04 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 25 12:43:04 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 25 12:43:04 volumio volumio[1954]: info: Discovery: Getting this device information Jan 25 12:43:04 volumio volumio[1954]: info: CoreCommandRouter::volumioGetState Jan 25 12:43:04 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 25 12:43:08 volumio sudo[4626]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 25 12:43:08 volumio sudo[4626]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:43:08 volumio sudo[4626]: pam_unix(sudo:session): session closed for user root Jan 25 12:43:08 volumio sudo[4628]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 25 12:43:08 volumio sudo[4628]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:43:08 volumio sudo[4628]: pam_unix(sudo:session): session closed for user root Jan 25 12:43:08 volumio volumio[1954]: verbose: New Socket.io Connection to 192.168.1.102 from 192.168.1.217 UA: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:147.0) Gecko/20100101 Firefox/147.0 Engine version: 3 Transport: polling Total Clients: 6 Jan 25 12:43:08 volumio volumio[1954]: info: CoreCommandRouter::volumioGetState Jan 25 12:43:08 volumio volumio[1954]: info: Received Get System Info Jan 25 12:43:08 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 25 12:43:08 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 25 12:43:08 volumio volumio[1954]: info: Discovery: Getting this device information Jan 25 12:43:08 volumio volumio[1954]: info: CoreCommandRouter::volumioGetState Jan 25 12:43:08 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 25 12:43:08 volumio volumio[1954]: info: CoreCommandRouter::volumioGetState Jan 25 12:43:08 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 25 12:43:08 volumio volumio[1954]: info: CoreCommandRouter::volumioGetVisibleSources Jan 25 12:43:08 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 12:43:08 volumio volumio[1954]: info: CoreCommandRouter::volumioGetState Jan 25 12:43:08 volumio volumio[1954]: info: CoreCommandRouter::volumioGetState Jan 25 12:43:08 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 25 12:43:08 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 25 12:43:08 volumio volumio[1954]: info: Received Get System Info Jan 25 12:43:08 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 25 12:43:08 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 25 12:43:08 volumio volumio[1954]: info: Discovery: Getting this device information Jan 25 12:43:08 volumio volumio[1954]: info: CoreCommandRouter::volumioGetState Jan 25 12:43:08 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 25 12:43:08 volumio volumio[1954]: info: CoreCommandRouter::volumioGetState Jan 25 12:43:08 volumio volumio[1954]: info: Listing playlists Jan 25 12:43:08 volumio volumio[1954]: info: CoreCommandRouter::volumioGetQueue Jan 25 12:43:08 volumio volumio[1954]: info: CoreStateMachine::getQueue Jan 25 12:43:08 volumio volumio[1954]: info: CorePlayQueue::getQueue Jan 25 12:43:09 volumio volumio[1954]: info: Received Get System Info Jan 25 12:43:09 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 25 12:43:09 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 25 12:43:09 volumio volumio[1954]: info: Discovery: Getting this device information Jan 25 12:43:09 volumio volumio[1954]: info: CoreCommandRouter::volumioGetState Jan 25 12:43:09 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 25 12:43:09 volumio volumio[1954]: info: CoreCommandRouter::volumioGetState Jan 25 12:43:09 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jan 25 12:43:09 volumio volumio[1954]: info: CoreCommandRouter::volumioGetState Jan 25 12:43:09 volumio volumio[1954]: info: Jan 25 12:43:09 volumio volumio[1954]: ---------------------------- MPD announces system playlist update Jan 25 12:43:09 volumio volumio[1954]: info: Ignoring MPD Status Update Jan 25 12:43:09 volumio volumio[1954]: info: Jan 25 12:43:09 volumio volumio[1954]: ---------------------------- MPD announces state update: player Jan 25 12:43:09 volumio volumio[1954]: info: ControllerMpd::getState Jan 25 12:43:09 volumio volumio[1954]: verbose: ControllerMpd::sendMpdCommand status Jan 25 12:43:09 volumio volumio[1954]: info: Jan 25 12:43:09 volumio volumio[1954]: ---------------------------- MPD announces system playlist update Jan 25 12:43:09 volumio volumio[1954]: info: Ignoring MPD Status Update Jan 25 12:43:09 volumio volumio[1954]: info: Jan 25 12:43:09 volumio volumio[1954]: ---------------------------- MPD announces state update: player Jan 25 12:43:09 volumio volumio[1954]: info: ControllerMpd::getState Jan 25 12:43:09 volumio volumio[1954]: verbose: ControllerMpd::sendMpdCommand status Jan 25 12:43:09 volumio volumio[1954]: info: Jan 25 12:43:09 volumio volumio[1954]: ---------------------------- MPD announces system playlist update Jan 25 12:43:09 volumio volumio[1954]: info: Ignoring MPD Status Update Jan 25 12:43:09 volumio volumio[1954]: info: Jan 25 12:43:09 volumio volumio[1954]: ---------------------------- MPD announces state update: player Jan 25 12:43:09 volumio volumio[1954]: info: ControllerMpd::getState Jan 25 12:43:09 volumio volumio[1954]: verbose: ControllerMpd::sendMpdCommand status Jan 25 12:43:09 volumio volumio[1954]: info: ------------------------------ 16ms Jan 25 12:43:09 volumio volumio[1954]: info: sendMpdCommand status took 13 milliseconds Jan 25 12:43:09 volumio volumio[1954]: info: ------------------------------ 12ms Jan 25 12:43:09 volumio volumio[1954]: verbose: ControllerMpd::parseState Jan 25 12:43:09 volumio volumio[1954]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 12:43:09 volumio volumio[1954]: info: sendMpdCommand status took 16 milliseconds Jan 25 12:43:09 volumio volumio[1954]: info: ------------------------------ 14ms Jan 25 12:43:09 volumio volumio[1954]: info: sendMpdCommand status took 11 milliseconds Jan 25 12:43:09 volumio volumio[1954]: info: sendMpdCommand playlistinfo took 5 milliseconds Jan 25 12:43:09 volumio volumio[1954]: verbose: ControllerMpd::parseState Jan 25 12:43:09 volumio volumio[1954]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 12:43:09 volumio volumio[1954]: verbose: ControllerMpd::parseState Jan 25 12:43:09 volumio volumio[1954]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 12:43:09 volumio volumio[1954]: verbose: ControllerMpd::parseTrackInfo Jan 25 12:43:09 volumio volumio[1954]: info: ControllerMpd::pushState Jan 25 12:43:09 volumio volumio[1954]: info: CoreCommandRouter::servicePushState Jan 25 12:43:09 volumio volumio[1954]: info: CorePlayQueue::getTrack 0 Jan 25 12:43:09 volumio volumio[1954]: verbose: STATE SERVICE {"status":"play","position":0,"seek":31357,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Chubby Checker - Let's Twist Again","artist":"Goldies","album":null,"uri":"https://stream.streambase.ch/r32goldies/mp3-192/tunein/","trackType":""} Jan 25 12:43:09 volumio volumio[1954]: verbose: CURRENT POSITION 0 Jan 25 12:43:09 volumio volumio[1954]: info: CoreStateMachine::syncState stateService play Jan 25 12:43:09 volumio volumio[1954]: info: CoreStateMachine::syncState currentStatus play Jan 25 12:43:09 volumio volumio[1954]: info: Received an update from plugin. extracting info from payload Jan 25 12:43:09 volumio volumio[1954]: info: CoreStateMachine::pushState Jan 25 12:43:09 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 12:43:10 volumio volumio[1954]: info: CoreCommandRouter::volumioPushState Jan 25 12:43:10 volumio volumio[1954]: info: CoreStateMachine::pushState Jan 25 12:43:10 volumio volumio[1954]: info: CoreCommandRouter::volumioPushState Jan 25 12:43:10 volumio volumio[1954]: info: ------------------------------ 94ms Jan 25 12:43:10 volumio volumio[1954]: info: sendMpdCommand playlistinfo took 70 milliseconds Jan 25 12:43:10 volumio volumio[1954]: info: sendMpdCommand playlistinfo took 70 milliseconds Jan 25 12:43:10 volumio volumio[1954]: verbose: ControllerMpd::parseTrackInfo Jan 25 12:43:10 volumio volumio[1954]: verbose: ControllerMpd::parseTrackInfo Jan 25 12:43:10 volumio volumio[1954]: info: ControllerMpd::pushState Jan 25 12:43:10 volumio volumio[1954]: info: CoreCommandRouter::servicePushState Jan 25 12:43:10 volumio volumio[1954]: info: CorePlayQueue::getTrack 0 Jan 25 12:43:10 volumio volumio[1954]: verbose: STATE SERVICE {"status":"play","position":0,"seek":31357,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Chubby Checker - Let's Twist Again","artist":"Goldies","album":null,"uri":"https://stream.streambase.ch/r32goldies/mp3-192/tunein/","trackType":""} Jan 25 12:43:10 volumio volumio[1954]: verbose: CURRENT POSITION 0 Jan 25 12:43:10 volumio volumio[1954]: info: CoreStateMachine::syncState stateService play Jan 25 12:43:10 volumio volumio[1954]: info: CoreStateMachine::syncState currentStatus play Jan 25 12:43:10 volumio volumio[1954]: info: Received an update from plugin. extracting info from payload Jan 25 12:43:10 volumio volumio[1954]: info: CoreStateMachine::pushState Jan 25 12:43:10 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 12:43:10 volumio volumio[1954]: info: CoreCommandRouter::volumioPushState Jan 25 12:43:10 volumio volumio[1954]: info: CoreStateMachine::pushState Jan 25 12:43:10 volumio volumio[1954]: info: CoreCommandRouter::volumioPushState Jan 25 12:43:10 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 25 12:43:10 volumio volumio[1954]: info: ControllerMpd::pushState Jan 25 12:43:10 volumio volumio[1954]: info: CoreCommandRouter::servicePushState Jan 25 12:43:10 volumio volumio[1954]: info: CorePlayQueue::getTrack 0 Jan 25 12:43:10 volumio volumio[1954]: verbose: STATE SERVICE {"status":"play","position":0,"seek":31357,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Chubby Checker - Let's Twist Again","artist":"Goldies","album":null,"uri":"https://stream.streambase.ch/r32goldies/mp3-192/tunein/","trackType":""} Jan 25 12:43:10 volumio volumio[1954]: verbose: CURRENT POSITION 0 Jan 25 12:43:10 volumio volumio[1954]: info: CoreStateMachine::syncState stateService play Jan 25 12:43:10 volumio volumio[1954]: info: CoreStateMachine::syncState currentStatus play Jan 25 12:43:10 volumio volumio[1954]: info: Received an update from plugin. extracting info from payload Jan 25 12:43:10 volumio volumio[1954]: info: CoreStateMachine::pushState Jan 25 12:43:10 volumio volumio[1954]: info: CoreCommandRouter::volumioPushState Jan 25 12:43:10 volumio volumio[1954]: info: CoreStateMachine::pushState Jan 25 12:43:10 volumio volumio[1954]: info: CoreCommandRouter::volumioPushState Jan 25 12:43:10 volumio volumio[1954]: info: ------------------------------ 215ms Jan 25 12:43:10 volumio volumio[1954]: info: ------------------------------ 212ms Jan 25 12:43:10 volumio volumio[1954]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Jan 25 12:43:10 volumio volumio[1954]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Jan 25 12:43:10 volumio volumio[1954]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Jan 25 12:43:10 volumio volumio[1954]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Jan 25 12:43:10 volumio volumio[1954]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Jan 25 12:43:10 volumio volumio[1954]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Jan 25 12:43:18 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 25 12:43:19 volumio volumio[1954]: info: CoreCommandRouter::volumioGetState Jan 25 12:43:20 volumio kernel: hwmon hwmon1: Voltage normalised Jan 25 12:43:24 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 25 12:43:24 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 25 12:43:28 volumio volumio[1954]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 25 12:43:35 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 25 12:43:39 volumio kernel: hwmon hwmon1: Voltage normalised Jan 25 12:43:43 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 25 12:43:47 volumio kernel: hwmon hwmon1: Voltage normalised Jan 25 12:44:07 volumio systemd[1]: Starting systemd-tmpfiles-clean.service - Cleanup of Temporary Directories... Jan 25 12:44:07 volumio systemd[1]: systemd-tmpfiles-clean.service: Deactivated successfully. Jan 25 12:44:07 volumio systemd[1]: Finished systemd-tmpfiles-clean.service - Cleanup of Temporary Directories. Jan 25 12:44:07 volumio systemd[1]: run-credentials-systemd\x2dtmpfiles\x2dclean.service.mount: Deactivated successfully. Jan 25 12:44:12 volumio volumio[1954]: info: Received OAUTH Data Jan 25 12:44:12 volumio volumio[1954]: info: Executing Spotify Oauth Login Jan 25 12:44:12 volumio volumio[1954]: info: Saving Spotify Refresh Token Jan 25 12:44:12 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 25 12:44:12 volumio sudo[4906]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 25 12:44:12 volumio sudo[4906]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:44:12 volumio sudo[4906]: pam_unix(sudo:session): session closed for user root Jan 25 12:44:12 volumio volumio[1954]: info: New Spotify access tokenBQBqKp7zss... Jan 25 12:44:12 volumio volumio[1954]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 25 12:44:12 volumio sudo[4908]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 25 12:44:12 volumio sudo[4908]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:44:12 volumio sudo[4908]: pam_unix(sudo:session): session closed for user root Jan 25 12:44:12 volumio volumio[1954]: verbose: New Socket.io Connection to 192.168.1.102 from 192.168.1.217 UA: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:147.0) Gecko/20100101 Firefox/147.0 Engine version: 3 Transport: polling Total Clients: 5 Jan 25 12:44:12 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 25 12:44:12 volumio volumio[1954]: info: CoreCommandRouter::volumioGetVisibleSources Jan 25 12:44:12 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 12:44:12 volumio volumio[1954]: info: CoreCommandRouter::volumioGetState Jan 25 12:44:12 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 25 12:44:12 volumio volumio[1954]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 25 12:44:12 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 25 12:44:12 volumio volumio[1954]: info: Received Get System Info Jan 25 12:44:12 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 25 12:44:12 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 25 12:44:12 volumio volumio[1954]: info: Discovery: Getting this device information Jan 25 12:44:12 volumio volumio[1954]: info: CoreCommandRouter::volumioGetState Jan 25 12:44:12 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 25 12:44:12 volumio volumio[1954]: info: CoreCommandRouter::volumioGetState Jan 25 12:44:13 volumio volumio[1954]: info: Listing playlists Jan 25 12:44:13 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 25 12:44:13 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 25 12:44:13 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jan 25 12:44:13 volumio volumio[1954]: SPOTIFY: User informations: {"country":"CH","display_name":"speichenblitz","email":"schmuckli@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/speichenblitz"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/speichenblitz","id":"speichenblitz","images":[],"product":"premium","type":"user","uri":"spotify:user:speichenblitz"} Jan 25 12:44:13 volumio volumio[1954]: info: Creating Spotify config file Jan 25 12:44:13 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:44:13 volumio volumio[1954]: info: Spotify config file written Jan 25 12:44:13 volumio sudo[4915]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 25 12:44:13 volumio sudo[4915]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:44:13 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 25 12:44:13 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 25 12:44:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:44:13 volumio systemd[1]: go-librespot-daemon.service: Consumed 1.023s CPU time. Jan 25 12:44:13 volumio volumio[1954]: info: Connection to go-librespot Websocket closed Jan 25 12:44:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:44:13 volumio go-librespot[4917]: go-librespot daemon starting... Jan 25 12:44:13 volumio sudo[4915]: pam_unix(sudo:session): session closed for user root Jan 25 12:44:13 volumio volumio[1954]: info: New Spotify access tokenBQA64NnSLR... Jan 25 12:44:13 volumio volumio[1954]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 25 12:44:13 volumio go-librespot[4918]: time="2026-01-25T12:44:13+01:00" level=info msg="running go-librespot 0.6.2" Jan 25 12:44:13 volumio go-librespot[4918]: time="2026-01-25T12:44:13+01:00" level=debug msg="app state loaded" Jan 25 12:44:13 volumio go-librespot[4918]: time="2026-01-25T12:44:13+01:00" level=debug msg="stored credentials not found" Jan 25 12:44:13 volumio go-librespot[4918]: time="2026-01-25T12:44:13+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 12:44:14 volumio volumio[1954]: SPOTIFY: User informations: {"country":"CH","display_name":"speichenblitz","email":"schmuckli@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/speichenblitz"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/speichenblitz","id":"speichenblitz","images":[],"product":"premium","type":"user","uri":"spotify:user:speichenblitz"} Jan 25 12:44:14 volumio volumio[1954]: info: Spotify Successfully logged in Jan 25 12:44:14 volumio volumio[1954]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 12:44:14 volumio volumio[1954]: info: [1769341454028] CoreMusicLibrary::Adding element Spotify Jan 25 12:44:14 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 12:44:14 volumio volumio[1954]: Cannot find translation for source Spotify Jan 25 12:44:14 volumio go-librespot[4918]: time="2026-01-25T12:44:14+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 25 12:44:14 volumio go-librespot[4918]: time="2026-01-25T12:44:14+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 25 12:44:14 volumio go-librespot[4918]: time="2026-01-25T12:44:14+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 25 12:44:14 volumio go-librespot[4918]: time="2026-01-25T12:44:14+01:00" level=info msg="zeroconf server listening on port 35435" Jan 25 12:44:14 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 25 12:44:14 volumio volumio[1954]: info: Received Get System Info Jan 25 12:44:14 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 25 12:44:14 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 25 12:44:14 volumio volumio[1954]: info: Discovery: Getting this device information Jan 25 12:44:14 volumio volumio[1954]: info: CoreCommandRouter::volumioGetState Jan 25 12:44:14 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 25 12:44:14 volumio go-librespot[4918]: time="2026-01-25T12:44:14+01:00" level=debug msg="obtained new client token: AACkNmrBcI683+ctxug1minlww27F1kmrFBBi4uQhHu4MPjCi4ctNZZgEcSakc79F+BbmO2dr29tBf8srpNh1e2k8JVGWXgD67I9msXHpNzRz6WcfpfWm53TKZgdFXcypbYuinJBIzgX8sdb6OvefUJ8+5YPOIyLVivyajr+NAw8xwxGwJD6x6ccLAeXFzc18o08Nnv6Mck4EhU3yUQ8L7hX0zz+ZxejNAgV3V5gGOEbp5O06+PulzU=" Jan 25 12:44:14 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jan 25 12:44:14 volumio go-librespot[4918]: time="2026-01-25T12:44:14+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Jan 25 12:44:14 volumio go-librespot[4918]: time="2026-01-25T12:44:14+01:00" level=debug msg="completed keyexchange" Jan 25 12:44:14 volumio go-librespot[4918]: time="2026-01-25T12:44:14+01:00" level=debug msg="completed challenge" Jan 25 12:44:14 volumio go-librespot[4918]: time="2026-01-25T12:44:14+01:00" level=info msg="authenticated AP" username="sp*********tz" Jan 25 12:44:15 volumio go-librespot[4918]: time="2026-01-25T12:44:15+01:00" level=info msg="authenticated Login5" username="sp*********tz" Jan 25 12:44:15 volumio go-librespot[4918]: time="2026-01-25T12:44:15+01:00" level=debug msg="stored credentials" username="sp*********tz" Jan 25 12:44:15 volumio go-librespot[4918]: time="2026-01-25T12:44:15+01:00" level=debug msg="initializing zeroconf session" username="sp*********tz" Jan 25 12:44:15 volumio go-librespot[4918]: time="2026-01-25T12:44:15+01:00" level=debug msg="dealer connection opened" Jan 25 12:44:15 volumio go-librespot[4918]: time="2026-01-25T12:44:15+01:00" level=trace msg="starting accesspoint recv loop" Jan 25 12:44:15 volumio go-librespot[4918]: time="2026-01-25T12:44:15+01:00" level=trace msg="starting dealer recv loop" Jan 25 12:44:15 volumio go-librespot[4918]: time="2026-01-25T12:44:15+01:00" level=trace msg="received accesspoint ping" Jan 25 12:44:15 volumio go-librespot[4918]: time="2026-01-25T12:44:15+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jan 25 12:44:15 volumio go-librespot[4918]: time="2026-01-25T12:44:15+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jan 25 12:44:15 volumio go-librespot[4918]: time="2026-01-25T12:44:15+01:00" level=debug msg="received connection id: MDA4YjA2N2YtZjQx...NDNDMjIzMDM1NQ==" Jan 25 12:44:15 volumio go-librespot[4918]: time="2026-01-25T12:44:15+01:00" level=debug msg="put connect state because NEW_DEVICE" Jan 25 12:44:15 volumio go-librespot[4918]: time="2026-01-25T12:44:15+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jan 25 12:44:15 volumio go-librespot[4918]: time="2026-01-25T12:44:15+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jan 25 12:44:15 volumio go-librespot[4918]: time="2026-01-25T12:44:15+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jan 25 12:44:16 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 25 12:44:16 volumio volumio[1954]: info: Received Get System Info Jan 25 12:44:16 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 25 12:44:16 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 25 12:44:16 volumio volumio[1954]: info: Discovery: Getting this device information Jan 25 12:44:16 volumio volumio[1954]: info: CoreCommandRouter::volumioGetState Jan 25 12:44:16 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 25 12:44:16 volumio volumio[1954]: info: Initializing connection to go-librespot Websocket Jan 25 12:44:16 volumio go-librespot[4918]: time="2026-01-25T12:44:16+01:00" level=debug msg="new websocket client" Jan 25 12:44:16 volumio volumio[1954]: info: Connection to go-librespot Websocket established Jan 25 12:44:16 volumio volumio[1954]: info: go-librespot daemon successfully initialized Jan 25 12:44:16 volumio go-librespot[4918]: time="2026-01-25T12:44:16+01:00" level=trace msg="received accesspoint pong ack" Jan 25 12:44:18 volumio volumio[1954]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Jan 25 12:44:18 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Jan 25 12:44:18 volumio volumio[1954]: info: Creating Spotify config file Jan 25 12:44:18 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:44:18 volumio volumio[1954]: info: Spotify config file written Jan 25 12:44:18 volumio sudo[4951]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 25 12:44:18 volumio sudo[4951]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:44:18 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 25 12:44:18 volumio systemd[1]: go-librespot-daemon.service: Killing process 4939 (go-librespot) with signal SIGKILL. Jan 25 12:44:18 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 25 12:44:18 volumio volumio[1954]: info: Connection to go-librespot Websocket closed Jan 25 12:44:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:44:18 volumio systemd[1]: go-librespot-daemon.service: Consumed 1.217s CPU time. Jan 25 12:44:18 volumio kernel: hwmon hwmon1: Voltage normalised Jan 25 12:44:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:44:18 volumio go-librespot[4955]: go-librespot daemon starting... Jan 25 12:44:18 volumio sudo[4951]: pam_unix(sudo:session): session closed for user root Jan 25 12:44:18 volumio go-librespot[4958]: time="2026-01-25T12:44:18+01:00" level=info msg="running go-librespot 0.6.2" Jan 25 12:44:18 volumio go-librespot[4958]: time="2026-01-25T12:44:18+01:00" level=debug msg="app state loaded" Jan 25 12:44:18 volumio go-librespot[4958]: time="2026-01-25T12:44:18+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 12:44:19 volumio go-librespot[4958]: time="2026-01-25T12:44:19+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 25 12:44:19 volumio go-librespot[4958]: time="2026-01-25T12:44:19+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 25 12:44:19 volumio go-librespot[4958]: time="2026-01-25T12:44:19+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 25 12:44:19 volumio go-librespot[4958]: time="2026-01-25T12:44:19+01:00" level=info msg="zeroconf server listening on port 43355" Jan 25 12:44:19 volumio go-librespot[4958]: time="2026-01-25T12:44:19+01:00" level=debug msg="obtained new client token: AAB4yQpFxf6JtCnBVjWCj8Ho6zUj7vGQ140z5yQ4NW+jJdKbsCbIDsPDGe4v64zJ8rGpUFN1tqb/XSMTxiCNteQ3LWqZim68Kc1KjV03cKFhCGmRnJFLUX5P2r2w1zY4soFU4iHtq1DorPab4s7u6YifIcJW6hl9rtqtt/4SM/2u7f3OROVtZQYEwyDtgrq/M1/HvCps3RmhMfG3R/HfXIv74C2gWFhj38R7nGbX8LyYowUAs4qTMz0=" Jan 25 12:44:19 volumio go-librespot[4958]: time="2026-01-25T12:44:19+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Jan 25 12:44:19 volumio volumio[1954]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Jan 25 12:44:19 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Jan 25 12:44:19 volumio volumio[1954]: info: Creating Spotify config file Jan 25 12:44:19 volumio go-librespot[4958]: time="2026-01-25T12:44:19+01:00" level=debug msg="completed keyexchange" Jan 25 12:44:19 volumio volumio[1954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:44:19 volumio go-librespot[4958]: time="2026-01-25T12:44:19+01:00" level=debug msg="completed challenge" Jan 25 12:44:19 volumio volumio[1954]: info: Getting Spotify volume Jan 25 12:44:19 volumio volumio[1954]: info: Initializing connection to go-librespot Websocket Jan 25 12:44:19 volumio volumio[1954]: info: Spotify config file written Jan 25 12:44:19 volumio go-librespot[4958]: time="2026-01-25T12:44:19+01:00" level=info msg="authenticated AP" username="sp*********tz" Jan 25 12:44:19 volumio go-librespot[4958]: time="2026-01-25T12:44:19+01:00" level=debug msg="new websocket client" Jan 25 12:44:19 volumio volumio[1954]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jan 25 12:44:19 volumio volumio[1954]: info: Connection to go-librespot Websocket established Jan 25 12:44:19 volumio sudo[4970]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 25 12:44:19 volumio sudo[4970]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:44:19 volumio volumio[1954]: info: CoreCommandRouter::volumioGetState Jan 25 12:44:19 volumio volumio[1954]: SPOTIFY: RECEIVED VOLUMIO VOLUME 51 Jan 25 12:44:19 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 25 12:44:19 volumio systemd[1]: go-librespot-daemon.service: Killing process 4960 (go-librespot) with signal SIGKILL. Jan 25 12:44:19 volumio volumio[1954]: info: Connection to go-librespot Websocket closed Jan 25 12:44:19 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 25 12:44:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:44:19 volumio volumio[1954]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 12:44:19 volumio volumio[1954]: Error: socket hang up Jan 25 12:44:19 volumio volumio[1954]: at connResetException (node:internal/errors:720:14) Jan 25 12:44:19 volumio volumio[1954]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 25 12:44:19 volumio volumio[1954]: at Socket.emit (node:events:526:35) Jan 25 12:44:19 volumio volumio[1954]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 25 12:44:19 volumio volumio[1954]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 25 12:44:19 volumio volumio[1954]: code: 'ECONNRESET', Jan 25 12:44:19 volumio volumio[1954]: response: undefined Jan 25 12:44:19 volumio volumio[1954]: } Jan 25 12:44:19 volumio volumio[1954]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 12:44:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:44:19 volumio go-librespot[4973]: go-librespot daemon starting... Jan 25 12:44:20 volumio sudo[4970]: pam_unix(sudo:session): session closed for user root Jan 25 12:44:20 volumio go-librespot[4977]: time="2026-01-25T12:44:20+01:00" level=info msg="running go-librespot 0.6.2" Jan 25 12:44:20 volumio go-librespot[4977]: time="2026-01-25T12:44:20+01:00" level=debug msg="app state loaded" Jan 25 12:44:20 volumio go-librespot[4977]: time="2026-01-25T12:44:20+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 12:44:20 volumio go-librespot[4977]: time="2026-01-25T12:44:20+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 25 12:44:20 volumio go-librespot[4977]: time="2026-01-25T12:44:20+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 25 12:44:20 volumio go-librespot[4977]: time="2026-01-25T12:44:20+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 25 12:44:20 volumio kernel: hwmon hwmon1: Undervoltage detected! Jan 25 12:44:20 volumio go-librespot[4977]: time="2026-01-25T12:44:20+01:00" level=info msg="zeroconf server listening on port 40961" Jan 25 12:44:20 volumio go-librespot[4977]: time="2026-01-25T12:44:20+01:00" level=debug msg="obtained new client token: AABAfF/mSpd87xHzq0gDCULXp2V3Mxk4eJeHVINAvz0DdPhRalIzCN0W3isihg1gEZIQrM7VyLoD3Ind3ZW+kH9Pf+wkN4DTdfdwQSbJOgqrdFPHkVanxBFzCNp383h/tyYXGpmzR05aByUeGgbyeYLbwtnbUQLfBbOKarunC6IRAouF/TK/f9t0cH4jDAEqOfShXtIm1mh5XC7qYJ4hPGy/te5alPNqxe2BBrvxbZpYkfaVf6NVnJ0=" Jan 25 12:44:21 volumio go-librespot[4977]: time="2026-01-25T12:44:21+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Jan 25 12:44:21 volumio go-librespot[4977]: time="2026-01-25T12:44:21+01:00" level=debug msg="completed keyexchange" Jan 25 12:44:21 volumio go-librespot[4977]: time="2026-01-25T12:44:21+01:00" level=debug msg="completed challenge" Jan 25 12:44:21 volumio go-librespot[4977]: time="2026-01-25T12:44:21+01:00" level=info msg="authenticated AP" username="sp*********tz" Jan 25 12:44:21 volumio go-librespot[4977]: time="2026-01-25T12:44:21+01:00" level=info msg="authenticated Login5" username="sp*********tz" Jan 25 12:44:21 volumio go-librespot[4977]: time="2026-01-25T12:44:21+01:00" level=debug msg="initializing zeroconf session" username="sp*********tz" Jan 25 12:44:21 volumio go-librespot[4977]: time="2026-01-25T12:44:21+01:00" level=debug msg="dealer connection opened" Jan 25 12:44:21 volumio go-librespot[4977]: time="2026-01-25T12:44:21+01:00" level=trace msg="starting accesspoint recv loop" Jan 25 12:44:21 volumio go-librespot[4977]: time="2026-01-25T12:44:21+01:00" level=trace msg="starting dealer recv loop" Jan 25 12:44:21 volumio go-librespot[4977]: time="2026-01-25T12:44:21+01:00" level=trace msg="received accesspoint ping" Jan 25 12:44:21 volumio go-librespot[4977]: time="2026-01-25T12:44:21+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jan 25 12:44:21 volumio go-librespot[4977]: time="2026-01-25T12:44:21+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jan 25 12:44:21 volumio go-librespot[4977]: time="2026-01-25T12:44:21+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jan 25 12:44:21 volumio go-librespot[4977]: time="2026-01-25T12:44:21+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jan 25 12:44:21 volumio go-librespot[4977]: time="2026-01-25T12:44:21+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jan 25 12:44:21 volumio go-librespot[4977]: time="2026-01-25T12:44:21+01:00" level=debug msg="received connection id: MjlkYTRjNTYtNDFk...MEFGQjZCMURDRg==" Jan 25 12:44:21 volumio go-librespot[4977]: time="2026-01-25T12:44:21+01:00" level=trace msg="received accesspoint pong ack" Jan 25 12:44:21 volumio go-librespot[4977]: time="2026-01-25T12:44:21+01:00" level=debug msg="put connect state because NEW_DEVICE" Jan 25 12:44:22 volumio sudo[4997]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-25 12:43' Jan 25 12:44:22 volumio sudo[4997]: 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="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"