Oct 12 05:38:00 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4580. Oct 12 05:38:00 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:00 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:00 bcik go-librespot[4481]: go-librespot daemon starting... Oct 12 05:38:00 bcik go-librespot[4482]: time="2026-10-12T05:38:00+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:00 bcik go-librespot[4482]: time="2026-10-12T05:38:00+02:00" level=debug msg="app state loaded" Oct 12 05:38:00 bcik go-librespot[4482]: time="2026-10-12T05:38:00+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:00 bcik go-librespot[4482]: time="2026-10-12T05:38:00+02: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]" Oct 12 05:38:00 bcik go-librespot[4482]: time="2026-10-12T05:38:00+02: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]" Oct 12 05:38:00 bcik go-librespot[4482]: time="2026-10-12T05:38:00+02: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]" Oct 12 05:38:00 bcik go-librespot[4482]: time="2026-10-12T05:38:00+02:00" level=info msg="zeroconf server listening on port 44793" Oct 12 05:38:00 bcik go-librespot[4482]: time="2026-10-12T05:38:00+02:00" level=debug msg="obtained new client token: AAEw4d61bZqIKd6Rbt+hrIEkWDrE3LmuSXJTWPjoewexDqvVfCRygjla6upAJdL3UQs8Xh7h68W4xJ0q8no/n5Y2cvTw8VV3HMkmfMlK4ahf/VnU2tmM7371Bers78x6ieqZYdQYPMoKT2LoL1ajHmPR69h62mosYOv3bEv3GV6Ee/jXi9eOXGxsi7MRi8rOME2FQ34m3p6st4DBioZW+ytz//Lvoioy09UCIrgcNqlrJL+k4u0J" Oct 12 05:38:00 bcik volumio[4104]: info: Initializing connection to go-librespot Websocket Oct 12 05:38:00 bcik go-librespot[4482]: time="2026-10-12T05:38:00+02:00" level=debug msg="new websocket client" Oct 12 05:38:00 bcik volumio[4104]: info: Connection to go-librespot Websocket established Oct 12 05:38:00 bcik go-librespot[4482]: time="2026-10-12T05:38:00+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:38:00 bcik go-librespot[4482]: time="2026-10-12T05:38:00+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:00 bcik go-librespot[4482]: time="2026-10-12T05:38:00+02:00" level=debug msg="completed challenge" Oct 12 05:38:00 bcik go-librespot[4482]: time="2026-10-12T05:38:00+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:00 bcik go-librespot[4482]: time="2026-10-12T05:38:00+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:00 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:00 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:00 bcik volumio[4104]: info: Connection to go-librespot Websocket closed Oct 12 05:38:03 bcik volumio[4104]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 12 05:38:03 bcik volumio[4104]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Oct 12 05:38:03 bcik volumio[4104]: info: CoreCommandRouter::volumioGetState Oct 12 05:38:03 bcik volumio[4104]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:03 bcik volumio[4104]: info: Getting Spotify volume Oct 12 05:38:03 bcik volumio[4104]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 05:38:03 bcik volumio[4104]: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:38:03 bcik volumio[4104]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Oct 12 05:38:03 bcik volumio[4104]: errno: -111, Oct 12 05:38:03 bcik volumio[4104]: code: 'ECONNREFUSED', Oct 12 05:38:03 bcik volumio[4104]: syscall: 'connect', Oct 12 05:38:03 bcik volumio[4104]: address: '127.0.0.1', Oct 12 05:38:03 bcik volumio[4104]: port: 9879, Oct 12 05:38:03 bcik volumio[4104]: response: undefined Oct 12 05:38:03 bcik volumio[4104]: } Oct 12 05:38:03 bcik volumio[4104]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 05:38:03 bcik sudo[4506]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-12 05:37' Oct 12 05:38:03 bcik sudo[4506]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:03 bcik sudo[4506]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:03 bcik volumio-remote-updater[9031]: [2026-10-12 05:38:03] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Oct 12 05:38:03 bcik volumio-remote-updater[9031]: [2026-10-12 05:38:03] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Oct 12 05:38:03 bcik volumio5-onboarding[1483]: time=2026-10-12T05:38:03.477+02:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Oct 12 05:38:03 bcik volumio5-onboarding[1483]: time=2026-10-12T05:38:03.478+02:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Oct 12 05:38:03 bcik systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:03 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4581. Oct 12 05:38:03 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:03 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:03 bcik systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 12 05:38:03 bcik systemd[1]: volumio.service: Consumed 6.381s CPU time. Oct 12 05:38:03 bcik go-librespot[4511]: go-librespot daemon starting... Oct 12 05:38:03 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 12 05:38:03 bcik go-librespot[4515]: time="2026-10-12T05:38:03+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:03 bcik go-librespot[4515]: time="2026-10-12T05:38:03+02:00" level=debug msg="app state loaded" Oct 12 05:38:03 bcik go-librespot[4515]: time="2026-10-12T05:38:03+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:03 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Oct 12 05:38:03 bcik go-librespot[4515]: time="2026-10-12T05:38:03+02: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]" Oct 12 05:38:03 bcik go-librespot[4515]: time="2026-10-12T05:38:03+02: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]" Oct 12 05:38:03 bcik go-librespot[4515]: time="2026-10-12T05:38:03+02: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]" Oct 12 05:38:03 bcik go-librespot[4515]: time="2026-10-12T05:38:03+02:00" level=info msg="zeroconf server listening on port 39055" Oct 12 05:38:03 bcik go-librespot[4515]: time="2026-10-12T05:38:03+02:00" level=debug msg="obtained new client token: AAHU63xeToRYnb6diunbfvZ6BXChgQWtUSq1Os/bdhi3XfllQmCTbMzUwNuYT7313laDt2435z9jbxDk5IQdoPLkwWzzAN6RUnY5bMz9ZQdsKslB8KRjDUc6vPsWzuKcQBch6plTf7pmPxHnedlXtRJQ3UPdvgpOMzQDWkIeB8/3yLsw2OK1aBMop6giMnjgfTZBAuLBeqPU4p4jjzhFXaP/pgnM8ge4n8ExrjEEN60U8NQ4OcrEPlI=" Oct 12 05:38:03 bcik go-librespot[4515]: time="2026-10-12T05:38:03+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Oct 12 05:38:03 bcik go-librespot[4515]: time="2026-10-12T05:38:03+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Oct 12 05:38:03 bcik go-librespot[4515]: time="2026-10-12T05:38:03+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:03 bcik go-librespot[4515]: time="2026-10-12T05:38:03+02:00" level=debug msg="completed challenge" Oct 12 05:38:03 bcik go-librespot[4515]: time="2026-10-12T05:38:03+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:03 bcik systemd[1]: volumio.service: Scheduled restart job, restart counter is at 21818. Oct 12 05:38:03 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 12 05:38:03 bcik systemd[1]: Stopped volumio.service - Volumio Backend Module. Oct 12 05:38:03 bcik systemd[1]: volumio.service: Consumed 6.381s CPU time. Oct 12 05:38:03 bcik systemd[1]: Started volumio.service - Volumio Backend Module. Oct 12 05:38:03 bcik go-librespot[4515]: time="2026-10-12T05:38:03+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:03 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Oct 12 05:38:03 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:03 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:04 bcik volumio[4531]: info: ------------------------------------------- Oct 12 05:38:04 bcik volumio[4531]: info: ----- Volumio3 ---- Oct 12 05:38:04 bcik volumio[4531]: info: ------------------------------------------- Oct 12 05:38:04 bcik volumio[4531]: info: ----- System startup ---- Oct 12 05:38:04 bcik volumio[4531]: info: ------------------------------------------- Oct 12 05:38:04 bcik volumio[4531]: info: MYVOLUMIO Environment detected Oct 12 05:38:04 bcik volumio[4531]: info: Plugin folders cleanup Oct 12 05:38:04 bcik volumio[4531]: info: Scanning into folder /volumio/app/plugins/ Oct 12 05:38:04 bcik volumio[4531]: info: Scanning category audio_interface Oct 12 05:38:04 bcik volumio[4531]: info: Scanning category miscellanea Oct 12 05:38:04 bcik volumio[4531]: info: Scanning category music_service Oct 12 05:38:04 bcik volumio[4531]: info: Scanning category plugins.json Oct 12 05:38:04 bcik volumio[4531]: info: Scanning category system_controller Oct 12 05:38:04 bcik volumio[4531]: info: Scanning category user_interface Oct 12 05:38:04 bcik volumio[4531]: info: Scanning into folder /data/plugins/ Oct 12 05:38:04 bcik volumio[4531]: info: Scanning category music_service Oct 12 05:38:04 bcik volumio[4531]: info: Plugin folders cleanup completed Oct 12 05:38:04 bcik volumio[4531]: info: ------------------------------------------- Oct 12 05:38:04 bcik volumio[4531]: info: ----- Core plugins startup ---- Oct 12 05:38:04 bcik volumio[4531]: info: ------------------------------------------- Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugins from folder /volumio/app/plugins/ Oct 12 05:38:04 bcik volumio[4531]: info: Adding plugin upnp to MyMusic Plugins Oct 12 05:38:04 bcik volumio[4531]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 12 05:38:04 bcik volumio[4531]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugins from folder /data/plugins/ Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "system"... Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "appearance"... Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "network"... Oct 12 05:38:04 bcik volumio[4531]: info: Refreshing Cached IP Addresses Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "services"... Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "volumio5onboarding"... Oct 12 05:38:04 bcik sudo[4559]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 05:38:04 bcik sudo[4559]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:04 bcik sudo[4561]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 05:38:04 bcik sudo[4561]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:04 bcik sudo[4559]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "alsa_controller"... Oct 12 05:38:04 bcik sudo[4561]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:04 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "wizard"... Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "networkfs"... Oct 12 05:38:04 bcik volumio[4531]: info: Starting Udev Watcher for removable devices Oct 12 05:38:04 bcik volumio[4531]: info: Ignoring mount for partition: boot Oct 12 05:38:04 bcik volumio[4531]: info: Ignoring mount for partition: volumio Oct 12 05:38:04 bcik volumio[4531]: info: Ignoring mount for partition: volumio_data Oct 12 05:38:04 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "volumio_command_line_client"... Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "upnp"... Oct 12 05:38:04 bcik volumio[4531]: info: [1791776284610] Starting Upmpd Daemon Oct 12 05:38:04 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "my_music"... Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "mpd"... Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "upnp_browser"... Oct 12 05:38:04 bcik volumio[4531]: info: Starting UPNP Browser Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "alarm-clock"... Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "airplay_emulation"... Oct 12 05:38:04 bcik volumio[4531]: info: Starting Shairport Sync Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "last_100"... Oct 12 05:38:04 bcik volumio[4531]: info: Loading plugin "webradio"... Oct 12 05:38:05 bcik volumio[4531]: info: Loading plugin "i2s_dacs"... Oct 12 05:38:05 bcik volumio[4531]: info: Loading plugin "volumiodiscovery"... Oct 12 05:38:05 bcik volumio[4531]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 12 05:38:05 bcik volumio[4531]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 05:38:05 bcik volumio[4531]: *** WARNING *** For more information see Oct 12 05:38:05 bcik volumio[4531]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 12 05:38:05 bcik volumio[4531]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 05:38:05 bcik volumio[4531]: *** WARNING *** For more information see Oct 12 05:38:05 bcik node[4531]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 12 05:38:05 bcik node[4531]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 05:38:05 bcik node[4531]: *** WARNING *** For more information see Oct 12 05:38:05 bcik node[4531]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 12 05:38:05 bcik node[4531]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 05:38:05 bcik node[4531]: *** WARNING *** For more information see Oct 12 05:38:05 bcik volumio[4531]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 12 05:38:05 bcik volumio[4531]: info: Discovery: Started advertising with name: Bącik Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 05:38:05 bcik volumio[4531]: info: Loading plugin "spop"... Oct 12 05:38:05 bcik volumio[4531]: info: Loading plugin "outputs"... Oct 12 05:38:05 bcik volumio[4531]: info: Loading plugin "albumart"... Oct 12 05:38:05 bcik volumio[4531]: info: Plugin example_plugin is not enabled Oct 12 05:38:05 bcik volumio[4531]: info: Loading plugin "inputs"... Oct 12 05:38:05 bcik volumio[4531]: info: Loading plugin "updater_comm"... Oct 12 05:38:05 bcik volumio[4531]: info: Plugin mpdemulation is not enabled Oct 12 05:38:05 bcik volumio[4531]: info: Loading plugin "rest_api"... Oct 12 05:38:05 bcik volumio[4531]: info: Loading plugin "websocket"... Oct 12 05:38:05 bcik volumio[4531]: info: Starting Socket.io Server version 1.7.4 Oct 12 05:38:05 bcik volumio[4531]: info: Loading plugin "radio_browser"... Oct 12 05:38:05 bcik volumio[4591]: Forking 3 albumart workers Oct 12 05:38:05 bcik volumio[4531]: info: Loading i18n strings for locale pl Oct 12 05:38:05 bcik volumio[4531]: Updating browse sources language Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::initPlayerControls Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: Express server listening on port 3000 Oct 12 05:38:05 bcik volumio[4531]: [Metrics] WebUI: 1s 290.43ms Oct 12 05:38:05 bcik volumio[4531]: info: CoreStateMachine::resetVolumioState Oct 12 05:38:05 bcik volumio[4531]: info: CoreStateMachine::getcurrentVolume Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::volumioRetrievevolume Oct 12 05:38:05 bcik volumio[4531]: info: Volumio Network Manager: Network status updated: 1 Oct 12 05:38:05 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: Reloading queue from file Oct 12 05:38:05 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:38:05 bcik volumio[4531]: info: CoreStateMachine::setRepeat false single undefined Oct 12 05:38:05 bcik volumio[4531]: info: CoreStateMachine::pushState Oct 12 05:38:05 bcik volumio[4531]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::volumioPushState Oct 12 05:38:05 bcik volumio[4531]: info: CoreStateMachine::setRandom false Oct 12 05:38:05 bcik volumio[4531]: info: CoreStateMachine::pushState Oct 12 05:38:05 bcik volumio[4531]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::volumioPushState Oct 12 05:38:05 bcik volumio[4531]: info: VolumeController:: Volume=41 Mute =false Oct 12 05:38:05 bcik volumio[4531]: info: CoreStateMachine::pushState Oct 12 05:38:05 bcik volumio[4531]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::volumioPushState Oct 12 05:38:05 bcik volumio[4531]: info: CoreStateMachine::updateTrackBlock Oct 12 05:38:05 bcik volumio[4531]: info: CorePlayQueue::getTrackBlock Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::volumioRetrievevolume Oct 12 05:38:05 bcik volumio[4531]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 12 05:38:05 bcik volumio[4531]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04171 Oct 12 05:38:05 bcik volumio[4531]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 12 05:38:05 bcik volumio[4531]: info: Setting Device type: Raspberry PI Oct 12 05:38:05 bcik volumio[4531]: info: Completed loading Core Plugins Oct 12 05:38:05 bcik volumio[4531]: info: Preparing to generate the ALSA configuration file Oct 12 05:38:05 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:38:05 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:38:05 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:38:05 bcik volumio[4531]: info: Asound.conf file unchanged, so no further update is needed Oct 12 05:38:05 bcik volumio[4531]: info: Output device has changed, restarting MPD Oct 12 05:38:05 bcik volumio[4531]: info: Output device has changed, restarting Shairport Sync Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:05 bcik sudo[4646]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 12 05:38:05 bcik sudo[4648]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 12 05:38:05 bcik sudo[4646]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:05 bcik sudo[4646]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:05 bcik sudo[4648]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:05 bcik volumio[4531]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 05:38:05 bcik volumio[4531]: info: ___________ START PLUGINS ___________ Oct 12 05:38:05 bcik volumio[4531]: info: ControllerMpd::onStart: Initializing MPD Oct 12 05:38:05 bcik volumio[4531]: info: Creating MPD Configuration file Oct 12 05:38:05 bcik systemd[1]: Stopping mpd.service - Music Player Daemon... Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 05:38:05 bcik volumio[4531]: info: [1791776285538] CoreMusicLibrary::Adding element Serwery Mediów Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:38:05 bcik volumio[4531]: info: UPNP Browser: Client initialized successfully Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:05 bcik sudo[4657]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Oct 12 05:38:05 bcik sudo[4658]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 12 05:38:05 bcik sudo[4658]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:05 bcik sudo[4660]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 12 05:38:05 bcik sudo[4660]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:05 bcik sudo[4658]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:05 bcik sudo[4657]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:05 bcik systemd[1]: mpd.service: Deactivated successfully. Oct 12 05:38:05 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 12 05:38:05 bcik systemd[1]: mpd.socket: Deactivated successfully. Oct 12 05:38:05 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 12 05:38:05 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 12 05:38:05 bcik volumio[4531]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 05:38:05 bcik volumio[4531]: info: [1791776285580] CoreMusicLibrary::Adding element Last_100 Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 05:38:05 bcik volumio[4531]: info: [1791776285581] CoreMusicLibrary::Adding element Webradio Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 05:38:05 bcik volumio[4531]: info: Initializing BBC Radios Oct 12 05:38:05 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 12 05:38:05 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Oct 12 05:38:05 bcik sudo[4657]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:05 bcik systemd[1]: mpd.service: Deactivated successfully. Oct 12 05:38:05 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 12 05:38:05 bcik systemd[1]: mpd.socket: Deactivated successfully. Oct 12 05:38:05 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 12 05:38:05 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 12 05:38:05 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:05 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Oct 12 05:38:05 bcik volumio[4531]: info: Creating Spotify config file Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik sudo[4688]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 12 05:38:05 bcik sudo[4688]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 12 05:38:05 bcik volumio[4602]: Starting albumart workers Oct 12 05:38:05 bcik volumio[4601]: Starting albumart workers Oct 12 05:38:05 bcik sudo[4688]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 05:38:05 bcik volumio[4531]: info: [1791776285742] CoreMusicLibrary::Adding element Radio Browser Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:38:05 bcik volumio[4531]: Cannot find translation for source Radio Browser Oct 12 05:38:05 bcik volumio[4531]: info: Volumio Calling Home Oct 12 05:38:05 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:38:05 bcik volumio[4531]: info: VolumeController:: Volume=41 Mute =false Oct 12 05:38:05 bcik volumio[4531]: info: CoreStateMachine::pushState Oct 12 05:38:05 bcik volumio[4531]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::volumioPushState Oct 12 05:38:05 bcik volumio[4531]: info: MPD Permissions set Oct 12 05:38:05 bcik volumio[4531]: info: MPD Permissions set Oct 12 05:38:05 bcik volumio[4531]: info: Spotify config file written Oct 12 05:38:05 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik sudo[4695]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 12 05:38:05 bcik sudo[4695]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:05 bcik volumio[4531]: info: No need to fix Spotify hosts Oct 12 05:38:05 bcik volumio[4603]: Starting albumart workers Oct 12 05:38:05 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:05 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:05 bcik go-librespot[4719]: go-librespot daemon starting... Oct 12 05:38:05 bcik sudo[4695]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:05 bcik go-librespot[4720]: time="2026-10-12T05:38:05+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:05 bcik go-librespot[4720]: time="2026-10-12T05:38:05+02:00" level=debug msg="app state loaded" Oct 12 05:38:05 bcik go-librespot[4720]: time="2026-10-12T05:38:05+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:05 bcik volumio[4531]: info: Volumio called home Oct 12 05:38:05 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:05 bcik volumio[4531]: info: Starting Shairport Sync Oct 12 05:38:05 bcik volumio[4531]: info: Starting Shairport Sync Oct 12 05:38:05 bcik volumio[4531]: info: Starting Shairport Sync Oct 12 05:38:05 bcik sudo[4728]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 12 05:38:05 bcik sudo[4728]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:05 bcik sudo[4732]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 12 05:38:05 bcik sudo[4732]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:05 bcik sudo[4730]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 12 05:38:05 bcik sudo[4730]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:06 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 12 05:38:06 bcik go-librespot[4720]: time="2026-10-12T05:38:06+02: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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 05:38:06 bcik go-librespot[4720]: time="2026-10-12T05:38:06+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 05:38:06 bcik go-librespot[4720]: time="2026-10-12T05:38:06+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 05:38:06 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Oct 12 05:38:06 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 12 05:38:06 bcik systemd[1]: shairport-sync.service: Consumed 1.523s CPU time. Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik go-librespot[4720]: time="2026-10-12T05:38:06+02:00" level=info msg="zeroconf server listening on port 43363" Oct 12 05:38:06 bcik volumio[4531]: info: An error occurred while refreshing Spotify Token Error: Bad Request Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: info: Discovery: adding f1ed5fb6-e21d-47c8-819b-29842600355e Oct 12 05:38:06 bcik volumio[4531]: info: Discovery: Found device Bącik Oct 12 05:38:06 bcik volumio[4531]: info: CoreCommandRouter::volumioGetState Oct 12 05:38:06 bcik volumio[4531]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:06 bcik volumio[4531]: info: Discovery: this is already registered, f1ed5fb6-e21d-47c8-819b-29842600355e Oct 12 05:38:06 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 12 05:38:06 bcik volumio[4531]: info: Discovery: Found device Bącik Oct 12 05:38:06 bcik volumio[4531]: info: CoreCommandRouter::volumioGetState Oct 12 05:38:06 bcik volumio[4531]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:06 bcik volumio[4531]: info: CoreCommandRouter::volumioGetState Oct 12 05:38:06 bcik volumio[4531]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:06 bcik sudo[4732]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:06 bcik sudo[4728]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:06 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 12 05:38:06 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Oct 12 05:38:06 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 12 05:38:06 bcik sudo[4730]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:06 bcik volumio[4531]: info: Shairport-Sync Started Oct 12 05:38:06 bcik volumio[4531]: Error adding Membership: Error: addMembership EINVAL Oct 12 05:38:06 bcik volumio[4531]: info: Shairport-Sync Started Oct 12 05:38:06 bcik go-librespot[4720]: time="2026-10-12T05:38:06+02:00" level=debug msg="obtained new client token: AAFTfQKELvtasCX++CCKXCUDeYdo0NZqHYGdeU3JcCCr8Ez9v8ISMTwjH5jUezJ1vlDJhA5RzuZrf1HPtqmRWZUkT7SSl7ISQhAWFG9M9zDQ4y6WjUnzcljs7KGoCKd2goBEQM+KGH8E8dik+uDKwYFFysvlKBnYU1hzaGtrCUuVTutsaVHbbpC6c8xs9iw3kwBSR9yebka+sMqa0MY3Z4Jmhqck110Z+fZFwuxt+72A2cYpG4wK" Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: info: Shairport-Sync Started Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik go-librespot[4720]: time="2026-10-12T05:38:06+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik go-librespot[4720]: time="2026-10-12T05:38:06+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:06 bcik go-librespot[4720]: time="2026-10-12T05:38:06+02:00" level=debug msg="completed challenge" Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik go-librespot[4720]: time="2026-10-12T05:38:06+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:06 bcik go-librespot[4720]: time="2026-10-12T05:38:06+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:06 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:06 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:06 bcik mpd[4690]: 2026-10-12T05:38:06 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 12 05:38:06 bcik systemd[1]: Started mpd.service - Music Player Daemon. Oct 12 05:38:06 bcik sudo[4648]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:06 bcik sudo[4660]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:06 bcik volumio[4531]: info: Completed starting Core Plugins Oct 12 05:38:06 bcik volumio[4531]: info: ------------------------------------------- Oct 12 05:38:06 bcik volumio[4531]: info: ----- MyVolumio plugins startup ---- Oct 12 05:38:06 bcik volumio[4531]: info: ------------------------------------------- Oct 12 05:38:06 bcik volumio[4531]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 12 05:38:06 bcik volumio[4531]: error: MPD error: The expression evaluated to a falsy value: Oct 12 05:38:06 bcik volumio[4531]: assert.ok(self.idling) Oct 12 05:38:06 bcik volumio[4531]: error: The expression evaluated to a falsy value: Oct 12 05:38:06 bcik volumio[4531]: assert.ok(self.idling) Oct 12 05:38:06 bcik volumio[4531]: error: updateQueue error: null Oct 12 05:38:06 bcik volumio[4531]: info: MPD running with PID4690 Oct 12 05:38:06 bcik volumio[4531]: ,establishing connection Oct 12 05:38:06 bcik volumio[4531]: error: updateQueue error: null Oct 12 05:38:08 bcik volumio-remote-updater[9031]: [2026-10-12 05:38:08] [connect] Successful connection Oct 12 05:38:08 bcik volumio-remote-updater[9031]: [2026-10-12 05:38:08] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1791776288 101 Oct 12 05:38:08 bcik volumio[4531]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 3 Oct 12 05:38:08 bcik volumio[4531]: info: go-librespot daemon successfully initialized Oct 12 05:38:09 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4582. Oct 12 05:38:09 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:09 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:09 bcik go-librespot[4767]: go-librespot daemon starting... Oct 12 05:38:09 bcik go-librespot[4768]: time="2026-10-12T05:38:09+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:09 bcik go-librespot[4768]: time="2026-10-12T05:38:09+02:00" level=debug msg="app state loaded" Oct 12 05:38:09 bcik go-librespot[4768]: time="2026-10-12T05:38:09+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:09 bcik go-librespot[4768]: time="2026-10-12T05:38:09+02: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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 05:38:09 bcik go-librespot[4768]: time="2026-10-12T05:38:09+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 05:38:09 bcik go-librespot[4768]: time="2026-10-12T05:38:09+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 05:38:09 bcik go-librespot[4768]: time="2026-10-12T05:38:09+02:00" level=info msg="zeroconf server listening on port 42733" Oct 12 05:38:09 bcik go-librespot[4768]: time="2026-10-12T05:38:09+02:00" level=debug msg="obtained new client token: AAH2fskJ04hIMyOCRqg48yRx+rhEqo+pR1JUz4jKal33BbnuMiDEA84M6M7fh9LOhZgoZWLfG1XK7+0w/zCWU4FCacBSc0UUy4SQaiBTiQEeal2v9cpkBSVk2noyRv4BF5n7TOi9x9FXtywAsHeCctE4L5hS6bFmddQUyOQbaQe1y58UrsubZNZ5IJpGD4GVgxqPZz+EZgcqVpPI6A1f3J7xBMBr4Cd4yP/L0g8Tr5dvJv3QCEv7uVI=" Oct 12 05:38:09 bcik go-librespot[4768]: time="2026-10-12T05:38:09+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:38:09 bcik go-librespot[4768]: time="2026-10-12T05:38:09+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:09 bcik go-librespot[4768]: time="2026-10-12T05:38:09+02:00" level=debug msg="completed challenge" Oct 12 05:38:09 bcik go-librespot[4768]: time="2026-10-12T05:38:09+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:09 bcik go-librespot[4768]: time="2026-10-12T05:38:09+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:09 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:09 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:11 bcik volumio[4531]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Oct 12 05:38:11 bcik volumio[4531]: info: Initializing connection to go-librespot Websocket Oct 12 05:38:11 bcik volumio[4531]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:38:12 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4583. Oct 12 05:38:12 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:12 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:12 bcik go-librespot[4777]: go-librespot daemon starting... Oct 12 05:38:12 bcik go-librespot[4778]: time="2026-10-12T05:38:12+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:12 bcik go-librespot[4778]: time="2026-10-12T05:38:12+02:00" level=debug msg="app state loaded" Oct 12 05:38:12 bcik go-librespot[4778]: time="2026-10-12T05:38:12+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:12 bcik go-librespot[4778]: time="2026-10-12T05:38:12+02: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]" Oct 12 05:38:12 bcik go-librespot[4778]: time="2026-10-12T05:38:12+02: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]" Oct 12 05:38:12 bcik go-librespot[4778]: time="2026-10-12T05:38:12+02: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]" Oct 12 05:38:12 bcik go-librespot[4778]: time="2026-10-12T05:38:12+02:00" level=info msg="zeroconf server listening on port 33081" Oct 12 05:38:12 bcik go-librespot[4778]: time="2026-10-12T05:38:12+02:00" level=debug msg="obtained new client token: AAEAl0y4cuFu/rU8A6UJwGYfcmItqG5IAKjAkO0EbuShg0YTnSem4mTcZEvBmxwIOVeeljqQtazIcjbDPZG9wn7fOFH2wUMJi7QEgdryI/JVKilh412MxElvalgcVzKE8aWD3MnI6FaUVYgggQUebPRSLsdLXdwdkqUCQfE+zwWRp6DlvhSuuJ0SES9njNhoTTZZUxJvkANnCdVUvrGFVYVwVjgGgh9Jw+ggZD1Ei2pmHzsu/WnGEQ0=" Oct 12 05:38:13 bcik go-librespot[4778]: time="2026-10-12T05:38:13+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:38:13 bcik go-librespot[4778]: time="2026-10-12T05:38:13+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:13 bcik go-librespot[4778]: time="2026-10-12T05:38:13+02:00" level=debug msg="completed challenge" Oct 12 05:38:13 bcik go-librespot[4778]: time="2026-10-12T05:38:13+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:13 bcik go-librespot[4778]: time="2026-10-12T05:38:13+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:13 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:13 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 12 05:38:14 bcik volumio[4531]: info: Adding plugin bluetooth to MyMusic Plugins Oct 12 05:38:14 bcik volumio[4531]: info: Adding plugin multiroom to MyMusic Plugins Oct 12 05:38:14 bcik volumio[4531]: info: Adding plugin metavolumio to MyMusic Plugins Oct 12 05:38:14 bcik volumio[4531]: info: Adding plugin cd_controller to MyMusic Plugins Oct 12 05:38:14 bcik volumio[4531]: info: Adding plugin qobuzconnect to MyMusic Plugins Oct 12 05:38:14 bcik volumio[4531]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 12 05:38:14 bcik volumio[4531]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 12 05:38:14 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:14 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:14 bcik volumio[4531]: info: Starting MyVolumio Remote Streaming Endpoints Oct 12 05:38:14 bcik volumio[4531]: info: MyVolumio login type: Token Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 12 05:38:14 bcik volumio[4531]: info: Streaming services startup Oct 12 05:38:14 bcik volumio[4531]: info: Starting Streaming Daemon Oct 12 05:38:14 bcik volumio[4531]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 12 05:38:14 bcik sudo[4802]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 12 05:38:14 bcik sudo[4802]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:14 bcik sudo[4802]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:14 bcik volumio[4531]: error: Cannot start Volumio Streaming Daemon Oct 12 05:38:14 bcik volumio[4531]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 12 05:38:14 bcik volumio[4531]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 12 05:38:14 bcik sudo[4809]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 05:38:14 bcik sudo[4809]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:14 bcik sudo[4811]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 05:38:14 bcik sudo[4811]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:14 bcik sudo[4811]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:14 bcik sudo[4809]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:14 bcik sudo[4815]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 12 05:38:14 bcik sudo[4815]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:14 bcik sudo[4815]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:14 bcik volumio[4531]: info: Upmpdcli Daemon Started Oct 12 05:38:14 bcik volumio[4531]: info: Initializing connection to go-librespot Websocket Oct 12 05:38:14 bcik volumio[4531]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:38:15 bcik volumio[4531]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 12 05:38:15 bcik volumio[4531]: info: MyVolumio token set successfully Oct 12 05:38:15 bcik volumio[4531]: info: MYVOLUMIO: Adding device Oct 12 05:38:15 bcik volumio[4531]: info: MYVOLUMIO: Evaluating Server Oct 12 05:38:15 bcik volumio[4531]: info: MyVolumio status changed Oct 12 05:38:15 bcik volumio[4531]: info: Streaming services startup Oct 12 05:38:15 bcik volumio[4531]: info: Starting Streaming Daemon Oct 12 05:38:15 bcik volumio[4531]: info: Removing browser output: myVolumio user plan is not superstar Oct 12 05:38:15 bcik volumio[4531]: info: Removing audio output: Oct 12 05:38:15 bcik volumio[4531]: info: Stoppping Tunnel 1 Oct 12 05:38:15 bcik sudo[4838]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 12 05:38:15 bcik sudo[4838]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:15 bcik sudo[4840]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Oct 12 05:38:15 bcik sudo[4840]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:15 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:38:15 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:38:15 bcik sudo[4838]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:15 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:38:15 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:38:15 bcik volumio[4531]: error: Cannot start Volumio Streaming Daemon Oct 12 05:38:15 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:38:15 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:38:15 bcik volumio[4531]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 12 05:38:15 bcik volumio[4531]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 12 05:38:15 bcik sudo[4840]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:15 bcik volumio[4531]: info: Remote SSH Stopped Oct 12 05:38:16 bcik volumio[4531]: info: Setting Geolocation for MyVolumio to eu6 Oct 12 05:38:16 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:16 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:16 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:16 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4584. Oct 12 05:38:16 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:16 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:16 bcik go-librespot[4843]: go-librespot daemon starting... Oct 12 05:38:16 bcik go-librespot[4844]: time="2026-10-12T05:38:16+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:16 bcik go-librespot[4844]: time="2026-10-12T05:38:16+02:00" level=debug msg="app state loaded" Oct 12 05:38:16 bcik go-librespot[4844]: time="2026-10-12T05:38:16+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:16 bcik go-librespot[4844]: time="2026-10-12T05:38:16+02: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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 05:38:16 bcik go-librespot[4844]: time="2026-10-12T05:38:16+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 05:38:16 bcik go-librespot[4844]: time="2026-10-12T05:38:16+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 05:38:16 bcik go-librespot[4844]: time="2026-10-12T05:38:16+02:00" level=info msg="zeroconf server listening on port 33539" Oct 12 05:38:16 bcik volumio[4531]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 12 05:38:16 bcik go-librespot[4844]: time="2026-10-12T05:38:16+02:00" level=debug msg="obtained new client token: AAGYSQe05BWTBuyvBttUwyJ25MTnjgoK9CIZfHxGNUPbNlBWVnDrU2UuE/P6Q8wt0YKOVQY1qtAusYLdjAQZEcEhYFNHKkUlII7UkHldCMmtJzDSP/F2T6Bo4szPLZN4YkXjKx1+laf7njQb2kE2nS7UPfr3LOOyG1tQe94nJeXLPcEBiPjsCh3saZwQNm3RYA0hAwgvc5Ms5+DzNHlx3b7htal95kswvwNfcVXtfxyBluv7kkJRyPU=" Oct 12 05:38:16 bcik go-librespot[4844]: time="2026-10-12T05:38:16+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:38:16 bcik go-librespot[4844]: time="2026-10-12T05:38:16+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:16 bcik go-librespot[4844]: time="2026-10-12T05:38:16+02:00" level=debug msg="completed challenge" Oct 12 05:38:16 bcik go-librespot[4844]: time="2026-10-12T05:38:16+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:16 bcik go-librespot[4844]: time="2026-10-12T05:38:16+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:16 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:16 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:17 bcik volumio[4531]: info: Updating MyVolumio device info Oct 12 05:38:17 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:17 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:17 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:17 bcik volumio[4531]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 12 05:38:17 bcik volumio[4531]: info: Initializing connection to go-librespot Websocket Oct 12 05:38:17 bcik volumio[4531]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:38:19 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4585. Oct 12 05:38:19 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:19 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:19 bcik go-librespot[4854]: go-librespot daemon starting... Oct 12 05:38:19 bcik go-librespot[4855]: time="2026-10-12T05:38:19+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:19 bcik go-librespot[4855]: time="2026-10-12T05:38:19+02:00" level=debug msg="app state loaded" Oct 12 05:38:19 bcik go-librespot[4855]: time="2026-10-12T05:38:19+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:19 bcik go-librespot[4855]: time="2026-10-12T05:38:19+02: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]" Oct 12 05:38:19 bcik go-librespot[4855]: time="2026-10-12T05:38:19+02: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]" Oct 12 05:38:19 bcik go-librespot[4855]: time="2026-10-12T05:38:19+02: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]" Oct 12 05:38:19 bcik go-librespot[4855]: time="2026-10-12T05:38:19+02:00" level=info msg="zeroconf server listening on port 35145" Oct 12 05:38:19 bcik go-librespot[4855]: time="2026-10-12T05:38:19+02:00" level=debug msg="obtained new client token: AAG5WNuvP7wSYtr8lvvK7sNWjdq4/SL0qM0PUtuOWfO60BkHeDDe6+nk1KAfcEvocdL4HsLTgjr0enhXyyZTTpfOOLEt9mNEOSsZIibmAiityx97Bs7E7joAMB19d5Eb/2h9cZ37Ohoj7qpwQ+J1jtRRJaxqjMR5aqDeFAFpSiC2MxeghJV82iiUiVHBslCB1sCf0GQXQgdrHptNZI5+//xUJ0JM+dg2hZWDM51op3hs7ZYGdiUWrKQ=" Oct 12 05:38:20 bcik go-librespot[4855]: time="2026-10-12T05:38:20+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:38:20 bcik go-librespot[4855]: time="2026-10-12T05:38:20+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:20 bcik go-librespot[4855]: time="2026-10-12T05:38:20+02:00" level=debug msg="completed challenge" Oct 12 05:38:20 bcik go-librespot[4855]: time="2026-10-12T05:38:20+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:20 bcik go-librespot[4855]: time="2026-10-12T05:38:20+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:20 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:20 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:20 bcik volumio[4531]: info: MYVOLUMIO: Adding device Oct 12 05:38:20 bcik volumio[4531]: info: MYVOLUMIO: Evaluating Server Oct 12 05:38:20 bcik volumio[4531]: info: Initializing connection to go-librespot Websocket Oct 12 05:38:20 bcik volumio[4531]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:38:20 bcik volumio[4531]: info: Setting Geolocation for MyVolumio to eu6 Oct 12 05:38:20 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:20 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:20 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:21 bcik volumio[4531]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 12 05:38:21 bcik volumio[4531]: info: Updating MyVolumio device info Oct 12 05:38:21 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:21 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:21 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:22 bcik volumio[4531]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 12 05:38:23 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4586. Oct 12 05:38:23 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:23 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:23 bcik go-librespot[4882]: go-librespot daemon starting... Oct 12 05:38:23 bcik go-librespot[4883]: time="2026-10-12T05:38:23+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:23 bcik go-librespot[4883]: time="2026-10-12T05:38:23+02:00" level=debug msg="app state loaded" Oct 12 05:38:23 bcik go-librespot[4883]: time="2026-10-12T05:38:23+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:23 bcik go-librespot[4883]: time="2026-10-12T05:38:23+02: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]" Oct 12 05:38:23 bcik go-librespot[4883]: time="2026-10-12T05:38:23+02: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]" Oct 12 05:38:23 bcik go-librespot[4883]: time="2026-10-12T05:38:23+02: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]" Oct 12 05:38:23 bcik go-librespot[4883]: time="2026-10-12T05:38:23+02:00" level=info msg="zeroconf server listening on port 36401" Oct 12 05:38:23 bcik go-librespot[4883]: time="2026-10-12T05:38:23+02:00" level=debug msg="obtained new client token: AAG0rIJ32kw+mBj+rpYWMcncBWJoBJqOxcli0Q8l3uCZOM9PmCH5Cb8vNslQ3Z45DM2u/jo+7sRPu4hlEJEy8ZiUyQEulpNInaPKLXPiYup+4/gAVyiAWEYJ9aeoMZEyBcoj/bQfpGK5pIh12mY5cuh+J0oyUcuHBKqUIEcyIuAkqE9MRLo5lKN5nMx1dkgJu0C19Y3iSbiykMj0INzwCwmxBkG8M2jfRhY1rFHiJbLSH4RrCLeoVCw=" Oct 12 05:38:23 bcik go-librespot[4883]: time="2026-10-12T05:38:23+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:38:23 bcik go-librespot[4883]: time="2026-10-12T05:38:23+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:23 bcik go-librespot[4883]: time="2026-10-12T05:38:23+02:00" level=debug msg="completed challenge" Oct 12 05:38:23 bcik go-librespot[4883]: time="2026-10-12T05:38:23+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:23 bcik go-librespot[4883]: time="2026-10-12T05:38:23+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:23 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:23 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:23 bcik volumio[4531]: info: Initializing connection to go-librespot Websocket Oct 12 05:38:23 bcik volumio[4531]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:38:26 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4587. Oct 12 05:38:26 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:26 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:26 bcik go-librespot[4906]: go-librespot daemon starting... Oct 12 05:38:26 bcik go-librespot[4907]: time="2026-10-12T05:38:26+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:26 bcik go-librespot[4907]: time="2026-10-12T05:38:26+02:00" level=debug msg="app state loaded" Oct 12 05:38:26 bcik go-librespot[4907]: time="2026-10-12T05:38:26+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:26 bcik go-librespot[4907]: time="2026-10-12T05:38:26+02: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]" Oct 12 05:38:26 bcik go-librespot[4907]: time="2026-10-12T05:38:26+02: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]" Oct 12 05:38:26 bcik go-librespot[4907]: time="2026-10-12T05:38:26+02: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]" Oct 12 05:38:26 bcik go-librespot[4907]: time="2026-10-12T05:38:26+02:00" level=info msg="zeroconf server listening on port 42303" Oct 12 05:38:26 bcik volumio[4531]: info: Initializing connection to go-librespot Websocket Oct 12 05:38:26 bcik go-librespot[4907]: time="2026-10-12T05:38:26+02:00" level=debug msg="new websocket client" Oct 12 05:38:26 bcik volumio[4531]: info: Connection to go-librespot Websocket established Oct 12 05:38:26 bcik go-librespot[4907]: time="2026-10-12T05:38:26+02:00" level=debug msg="obtained new client token: AAHFjoRMCpq8cqejDFph7m6cwSUiauiLMKEci79TGxT2etRv+Yg1lJQMHcND4DPekS9UApOjV6R+JV0b28+mT7/fXFNTypamCKuFpi8T1uLIUL4Rcl6zr+dyKm4ppr70usyWgLyccg908zYHlWEKmONzKRDjwOZk4yTeepw66gqDy3RlImE1SJS64G3A1eAblDVXMczvE5umEoUG5iOi+53HjhApEWfSdAqZ5+fUsWIpGmT+rOtz1b0=" Oct 12 05:38:27 bcik go-librespot[4907]: time="2026-10-12T05:38:27+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:38:27 bcik go-librespot[4907]: time="2026-10-12T05:38:27+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:27 bcik go-librespot[4907]: time="2026-10-12T05:38:27+02:00" level=debug msg="completed challenge" Oct 12 05:38:27 bcik go-librespot[4907]: time="2026-10-12T05:38:27+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:27 bcik go-librespot[4907]: time="2026-10-12T05:38:27+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:27 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:27 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:27 bcik volumio[4531]: info: Connection to go-librespot Websocket closed Oct 12 05:38:29 bcik volumio[4531]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 12 05:38:29 bcik volumio[4531]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Oct 12 05:38:29 bcik volumio[4531]: info: CoreCommandRouter::volumioGetState Oct 12 05:38:29 bcik volumio[4531]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:29 bcik volumio[4531]: info: Getting Spotify volume Oct 12 05:38:29 bcik volumio[4531]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 05:38:29 bcik volumio[4531]: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:38:29 bcik volumio[4531]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Oct 12 05:38:29 bcik volumio[4531]: errno: -111, Oct 12 05:38:29 bcik volumio[4531]: code: 'ECONNREFUSED', Oct 12 05:38:29 bcik volumio[4531]: syscall: 'connect', Oct 12 05:38:29 bcik volumio[4531]: address: '127.0.0.1', Oct 12 05:38:29 bcik volumio[4531]: port: 9879, Oct 12 05:38:29 bcik volumio[4531]: response: undefined Oct 12 05:38:29 bcik volumio[4531]: } Oct 12 05:38:29 bcik volumio[4531]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 05:38:30 bcik sudo[4930]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-12 05:37' Oct 12 05:38:30 bcik sudo[4930]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:30 bcik sudo[4930]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:30 bcik volumio-remote-updater[9031]: [2026-10-12 05:38:30] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Oct 12 05:38:30 bcik volumio-remote-updater[9031]: [2026-10-12 05:38:30] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Oct 12 05:38:30 bcik volumio5-onboarding[1483]: time=2026-10-12T05:38:30.192+02:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Oct 12 05:38:30 bcik volumio5-onboarding[1483]: time=2026-10-12T05:38:30.193+02:00 level=WARN msg="reconnection attempt failed" error="read tcp 127.0.0.1:46272->127.0.0.1:3000: read: connection reset by peer" Oct 12 05:38:30 bcik systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:30 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4588. Oct 12 05:38:30 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:30 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:30 bcik go-librespot[4935]: go-librespot daemon starting... Oct 12 05:38:30 bcik systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 12 05:38:30 bcik systemd[1]: volumio.service: Consumed 6.346s CPU time. Oct 12 05:38:30 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 12 05:38:30 bcik go-librespot[4944]: time="2026-10-12T05:38:30+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:30 bcik go-librespot[4944]: time="2026-10-12T05:38:30+02:00" level=debug msg="app state loaded" Oct 12 05:38:30 bcik go-librespot[4944]: time="2026-10-12T05:38:30+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:30 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Oct 12 05:38:30 bcik go-librespot[4944]: time="2026-10-12T05:38:30+02: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]" Oct 12 05:38:30 bcik go-librespot[4944]: time="2026-10-12T05:38:30+02: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]" Oct 12 05:38:30 bcik go-librespot[4944]: time="2026-10-12T05:38:30+02: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]" Oct 12 05:38:30 bcik go-librespot[4944]: time="2026-10-12T05:38:30+02:00" level=info msg="zeroconf server listening on port 33613" Oct 12 05:38:30 bcik go-librespot[4944]: time="2026-10-12T05:38:30+02:00" level=debug msg="obtained new client token: AAFfWtF5PSFOf8QWBKG/2SrNi3P73S44KzrZdEZ5OUA9+m5lCgXU2ZK3mLevp6GyYdCS2dNtzeNHc628LPNuFdlcW2e9QsGfBadtKROdsaOxiZUBtcuJplUnXsvI/Ulbaigvm0XKUOuqCwByt0yVknWtisFtDV9qd9DhN1bZ54025nAH3bQoLgDjL+usz4aEk1GjsfsI0xYDnEjAuVvwXlrMR6k2j0n0lyGN6vf6GZRtKtOIVlD2+uI=" Oct 12 05:38:30 bcik go-librespot[4944]: time="2026-10-12T05:38:30+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:38:30 bcik go-librespot[4944]: time="2026-10-12T05:38:30+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:30 bcik go-librespot[4944]: time="2026-10-12T05:38:30+02:00" level=debug msg="completed challenge" Oct 12 05:38:30 bcik go-librespot[4944]: time="2026-10-12T05:38:30+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:30 bcik go-librespot[4944]: time="2026-10-12T05:38:30+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:30 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:30 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:30 bcik systemd[1]: volumio.service: Scheduled restart job, restart counter is at 21819. Oct 12 05:38:30 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 12 05:38:30 bcik systemd[1]: Stopped volumio.service - Volumio Backend Module. Oct 12 05:38:30 bcik systemd[1]: volumio.service: Consumed 6.346s CPU time. Oct 12 05:38:30 bcik systemd[1]: Started volumio.service - Volumio Backend Module. Oct 12 05:38:30 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Oct 12 05:38:30 bcik volumio[4960]: info: ------------------------------------------- Oct 12 05:38:30 bcik volumio[4960]: info: ----- Volumio3 ---- Oct 12 05:38:30 bcik volumio[4960]: info: ------------------------------------------- Oct 12 05:38:30 bcik volumio[4960]: info: ----- System startup ---- Oct 12 05:38:30 bcik volumio[4960]: info: ------------------------------------------- Oct 12 05:38:31 bcik volumio[4960]: info: MYVOLUMIO Environment detected Oct 12 05:38:31 bcik volumio[4960]: info: Plugin folders cleanup Oct 12 05:38:31 bcik volumio[4960]: info: Scanning into folder /volumio/app/plugins/ Oct 12 05:38:31 bcik volumio[4960]: info: Scanning category audio_interface Oct 12 05:38:31 bcik volumio[4960]: info: Scanning category miscellanea Oct 12 05:38:31 bcik volumio[4960]: info: Scanning category music_service Oct 12 05:38:31 bcik volumio[4960]: info: Scanning category plugins.json Oct 12 05:38:31 bcik volumio[4960]: info: Scanning category system_controller Oct 12 05:38:31 bcik volumio[4960]: info: Scanning category user_interface Oct 12 05:38:31 bcik volumio[4960]: info: Scanning into folder /data/plugins/ Oct 12 05:38:31 bcik volumio[4960]: info: Scanning category music_service Oct 12 05:38:31 bcik volumio[4960]: info: Plugin folders cleanup completed Oct 12 05:38:31 bcik volumio[4960]: info: ------------------------------------------- Oct 12 05:38:31 bcik volumio[4960]: info: ----- Core plugins startup ---- Oct 12 05:38:31 bcik volumio[4960]: info: ------------------------------------------- Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugins from folder /volumio/app/plugins/ Oct 12 05:38:31 bcik volumio[4960]: info: Adding plugin upnp to MyMusic Plugins Oct 12 05:38:31 bcik volumio[4960]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 12 05:38:31 bcik volumio[4960]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugins from folder /data/plugins/ Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "system"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "appearance"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "network"... Oct 12 05:38:31 bcik volumio[4960]: info: Refreshing Cached IP Addresses Oct 12 05:38:31 bcik sudo[4990]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 05:38:31 bcik sudo[4990]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:31 bcik sudo[4992]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 05:38:31 bcik sudo[4992]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:31 bcik sudo[4990]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "services"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "volumio5onboarding"... Oct 12 05:38:31 bcik sudo[4992]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "alsa_controller"... Oct 12 05:38:31 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "wizard"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "networkfs"... Oct 12 05:38:31 bcik volumio[4960]: info: Starting Udev Watcher for removable devices Oct 12 05:38:31 bcik volumio[4960]: info: Ignoring mount for partition: boot Oct 12 05:38:31 bcik volumio[4960]: info: Ignoring mount for partition: volumio Oct 12 05:38:31 bcik volumio[4960]: info: Ignoring mount for partition: volumio_data Oct 12 05:38:31 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "volumio_command_line_client"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "upnp"... Oct 12 05:38:31 bcik volumio[4960]: info: [1791776311342] Starting Upmpd Daemon Oct 12 05:38:31 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "my_music"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "mpd"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "upnp_browser"... Oct 12 05:38:31 bcik volumio[4960]: info: Starting UPNP Browser Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "alarm-clock"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "airplay_emulation"... Oct 12 05:38:31 bcik volumio[4960]: info: Starting Shairport Sync Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "last_100"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "webradio"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "i2s_dacs"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "volumiodiscovery"... Oct 12 05:38:31 bcik volumio[4960]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 12 05:38:31 bcik volumio[4960]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 05:38:31 bcik volumio[4960]: *** WARNING *** For more information see Oct 12 05:38:31 bcik volumio[4960]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 12 05:38:31 bcik volumio[4960]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 05:38:31 bcik volumio[4960]: *** WARNING *** For more information see Oct 12 05:38:31 bcik volumio[4960]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 12 05:38:31 bcik node[4960]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 12 05:38:31 bcik node[4960]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 05:38:31 bcik node[4960]: *** WARNING *** For more information see Oct 12 05:38:31 bcik node[4960]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 12 05:38:31 bcik node[4960]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 05:38:31 bcik node[4960]: *** WARNING *** For more information see Oct 12 05:38:31 bcik volumio[4960]: info: Discovery: Started advertising with name: Bącik Oct 12 05:38:31 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "spop"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "outputs"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "albumart"... Oct 12 05:38:31 bcik volumio[4960]: info: Plugin example_plugin is not enabled Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "inputs"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "updater_comm"... Oct 12 05:38:31 bcik volumio[4960]: info: Plugin mpdemulation is not enabled Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "rest_api"... Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "websocket"... Oct 12 05:38:31 bcik volumio[4960]: info: Starting Socket.io Server version 1.7.4 Oct 12 05:38:31 bcik volumio[4960]: info: Loading plugin "radio_browser"... Oct 12 05:38:32 bcik volumio[5022]: Forking 3 albumart workers Oct 12 05:38:32 bcik volumio[4960]: info: Loading i18n strings for locale pl Oct 12 05:38:32 bcik volumio[4960]: Updating browse sources language Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::initPlayerControls Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: Express server listening on port 3000 Oct 12 05:38:32 bcik volumio[4960]: [Metrics] WebUI: 1s 272.09ms Oct 12 05:38:32 bcik volumio[4960]: info: CoreStateMachine::resetVolumioState Oct 12 05:38:32 bcik volumio[4960]: info: CoreStateMachine::getcurrentVolume Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::volumioRetrievevolume Oct 12 05:38:32 bcik volumio[4960]: info: Volumio Network Manager: Network status updated: 1 Oct 12 05:38:32 bcik volumio[4960]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:38:32 bcik volumio[4960]: info: VolumeController:: Volume=41 Mute =false Oct 12 05:38:32 bcik volumio[4960]: info: CoreStateMachine::pushState Oct 12 05:38:32 bcik volumio[4960]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::volumioPushState Oct 12 05:38:32 bcik volumio[4960]: info: CoreStateMachine::updateTrackBlock Oct 12 05:38:32 bcik volumio[4960]: info: CorePlayQueue::getTrackBlock Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::volumioRetrievevolume Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: Reloading queue from file Oct 12 05:38:32 bcik volumio[4960]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:38:32 bcik volumio[4960]: info: CoreStateMachine::setRepeat false single undefined Oct 12 05:38:32 bcik volumio[4960]: info: CoreStateMachine::pushState Oct 12 05:38:32 bcik volumio[4960]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::volumioPushState Oct 12 05:38:32 bcik volumio[4960]: info: CoreStateMachine::setRandom false Oct 12 05:38:32 bcik volumio[4960]: info: CoreStateMachine::pushState Oct 12 05:38:32 bcik volumio[4960]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::volumioPushState Oct 12 05:38:32 bcik volumio[4960]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 12 05:38:32 bcik volumio[4960]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04171 Oct 12 05:38:32 bcik volumio[4960]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 12 05:38:32 bcik volumio[4960]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:38:32 bcik volumio[4960]: info: Setting Device type: Raspberry PI Oct 12 05:38:32 bcik volumio[4960]: info: Completed loading Core Plugins Oct 12 05:38:32 bcik volumio[4960]: info: Preparing to generate the ALSA configuration file Oct 12 05:38:32 bcik volumio[4960]: info: VolumeController:: Volume=41 Mute =false Oct 12 05:38:32 bcik volumio[4960]: info: CoreStateMachine::pushState Oct 12 05:38:32 bcik volumio[4960]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::volumioPushState Oct 12 05:38:32 bcik volumio[4960]: info: Asound.conf file unchanged, so no further update is needed Oct 12 05:38:32 bcik volumio[4960]: info: Output device has changed, restarting MPD Oct 12 05:38:32 bcik volumio[4960]: info: Output device has changed, restarting Shairport Sync Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:32 bcik sudo[5077]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 12 05:38:32 bcik sudo[5077]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:32 bcik sudo[5077]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:32 bcik sudo[5081]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 12 05:38:32 bcik sudo[5081]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:32 bcik volumio[4960]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 05:38:32 bcik volumio[4960]: info: ___________ START PLUGINS ___________ Oct 12 05:38:32 bcik volumio[4960]: info: ControllerMpd::onStart: Initializing MPD Oct 12 05:38:32 bcik volumio[4960]: info: Creating MPD Configuration file Oct 12 05:38:32 bcik sudo[5086]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Oct 12 05:38:32 bcik sudo[5086]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 05:38:32 bcik volumio[4960]: info: [1791776312284] CoreMusicLibrary::Adding element Serwery Mediów Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:38:32 bcik volumio[4960]: info: UPNP Browser: Client initialized successfully Oct 12 05:38:32 bcik systemd[1]: Stopping mpd.service - Music Player Daemon... Oct 12 05:38:32 bcik sudo[5089]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 12 05:38:32 bcik sudo[5089]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:32 bcik sudo[5092]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 12 05:38:32 bcik sudo[5092]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:32 bcik sudo[5089]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:32 bcik systemd[1]: mpd.service: Deactivated successfully. Oct 12 05:38:32 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 12 05:38:32 bcik sudo[5086]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:32 bcik volumio[4960]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:32 bcik systemd[1]: mpd.socket: Deactivated successfully. Oct 12 05:38:32 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 12 05:38:32 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 12 05:38:32 bcik volumio[4960]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 05:38:32 bcik volumio[4960]: info: [1791776312329] CoreMusicLibrary::Adding element Last_100 Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 05:38:32 bcik volumio[4960]: info: [1791776312329] CoreMusicLibrary::Adding element Webradio Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 05:38:32 bcik volumio[4960]: info: Initializing BBC Radios Oct 12 05:38:32 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 12 05:38:32 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Oct 12 05:38:32 bcik systemd[1]: mpd.service: Deactivated successfully. Oct 12 05:38:32 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 12 05:38:32 bcik systemd[1]: mpd.socket: Deactivated successfully. Oct 12 05:38:32 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 12 05:38:32 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:32 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 12 05:38:32 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Oct 12 05:38:32 bcik volumio[4960]: info: Creating Spotify config file Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[5032]: Starting albumart workers Oct 12 05:38:32 bcik sudo[5119]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 12 05:38:32 bcik sudo[5119]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 12 05:38:32 bcik volumio[5034]: Starting albumart workers Oct 12 05:38:32 bcik sudo[5119]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:32 bcik volumio[5033]: Starting albumart workers Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 05:38:32 bcik volumio[4960]: info: [1791776312454] CoreMusicLibrary::Adding element Radio Browser Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:38:32 bcik volumio[4960]: Cannot find translation for source Radio Browser Oct 12 05:38:32 bcik volumio[4960]: info: Volumio Calling Home Oct 12 05:38:32 bcik volumio[4960]: info: MPD Permissions set Oct 12 05:38:32 bcik volumio[4960]: info: MPD Permissions set Oct 12 05:38:32 bcik volumio[4960]: info: Spotify config file written Oct 12 05:38:32 bcik volumio[4960]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Oct 12 05:38:32 bcik sudo[5137]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 12 05:38:32 bcik volumio[4960]: info: Volumio called home Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik sudo[5137]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:32 bcik volumio[4960]: info: No need to fix Spotify hosts Oct 12 05:38:32 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:32 bcik go-librespot[5145]: go-librespot daemon starting... Oct 12 05:38:32 bcik sudo[5137]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:32 bcik go-librespot[5152]: time="2026-10-12T05:38:32+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:32 bcik go-librespot[5152]: time="2026-10-12T05:38:32+02:00" level=debug msg="app state loaded" Oct 12 05:38:32 bcik go-librespot[5152]: time="2026-10-12T05:38:32+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:32 bcik volumio[4960]: info: Starting Shairport Sync Oct 12 05:38:32 bcik volumio[4960]: info: Starting Shairport Sync Oct 12 05:38:32 bcik volumio[4960]: info: Starting Shairport Sync Oct 12 05:38:32 bcik sudo[5167]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 12 05:38:32 bcik sudo[5167]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:32 bcik sudo[5170]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 12 05:38:32 bcik sudo[5170]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:32 bcik sudo[5171]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 12 05:38:32 bcik sudo[5171]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:32 bcik volumio[4960]: info: Discovery: adding f1ed5fb6-e21d-47c8-819b-29842600355e Oct 12 05:38:32 bcik volumio[4960]: info: Discovery: Found device Bącik Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::volumioGetState Oct 12 05:38:32 bcik volumio[4960]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:32 bcik volumio[4960]: info: Discovery: this is already registered, f1ed5fb6-e21d-47c8-819b-29842600355e Oct 12 05:38:32 bcik volumio[4960]: info: Discovery: Found device Bącik Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::volumioGetState Oct 12 05:38:32 bcik volumio[4960]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:32 bcik go-librespot[5152]: time="2026-10-12T05:38:32+02: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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 05:38:32 bcik go-librespot[5152]: time="2026-10-12T05:38:32+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 05:38:32 bcik go-librespot[5152]: time="2026-10-12T05:38:32+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 05:38:32 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 12 05:38:32 bcik volumio[4960]: info: CoreCommandRouter::volumioGetState Oct 12 05:38:32 bcik volumio[4960]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:32 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Oct 12 05:38:32 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 12 05:38:32 bcik systemd[1]: shairport-sync.service: Consumed 1.507s CPU time. Oct 12 05:38:32 bcik go-librespot[5152]: time="2026-10-12T05:38:32+02:00" level=info msg="zeroconf server listening on port 37093" Oct 12 05:38:32 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 12 05:38:32 bcik sudo[5170]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:32 bcik sudo[5167]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:32 bcik sudo[5171]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:32 bcik volumio[4960]: info: Shairport-Sync Started Oct 12 05:38:32 bcik volumio[4960]: Error adding Membership: Error: addMembership EINVAL Oct 12 05:38:32 bcik volumio[4960]: info: Shairport-Sync Started Oct 12 05:38:32 bcik volumio[4960]: info: Shairport-Sync Started Oct 12 05:38:32 bcik volumio[4960]: info: An error occurred while refreshing Spotify Token Error: Bad Request Oct 12 05:38:32 bcik go-librespot[5152]: time="2026-10-12T05:38:32+02:00" level=debug msg="obtained new client token: AAEhBnUCREmJMA5kGr9OXRU+RbO0DUPDKI+j+6+39AuvzyglNIUtr9XJ4eadyDU6cgbD7HMYn2CVY7id08FOhR7rcTqBN7vjqxErHyvKhJV5j7momuS9LIIXh07gkuzDIYmOA1Vr0l59TYf/Xip7+VWDM+21Hs4X4nSsQcvmFYhRVH38sE/Eq95aUke1l4GSmSklVfEyAazzfG2KIWqka/zBiNCq9TOHcKU3+pZ2tN7VyvX9uiCG1vY=" Oct 12 05:38:32 bcik go-librespot[5152]: time="2026-10-12T05:38:32+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:38:32 bcik go-librespot[5152]: time="2026-10-12T05:38:32+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:32 bcik go-librespot[5152]: time="2026-10-12T05:38:32+02:00" level=debug msg="completed challenge" Oct 12 05:38:32 bcik go-librespot[5152]: time="2026-10-12T05:38:32+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:32 bcik mpd[5121]: 2026-10-12T05:38:32 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 12 05:38:32 bcik systemd[1]: Started mpd.service - Music Player Daemon. Oct 12 05:38:32 bcik sudo[5092]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:32 bcik sudo[5081]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:32 bcik volumio[4960]: info: Completed starting Core Plugins Oct 12 05:38:32 bcik volumio[4960]: info: ------------------------------------------- Oct 12 05:38:32 bcik volumio[4960]: info: ----- MyVolumio plugins startup ---- Oct 12 05:38:32 bcik volumio[4960]: info: ------------------------------------------- Oct 12 05:38:32 bcik volumio[4960]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 12 05:38:32 bcik volumio[4960]: error: MPD error: The expression evaluated to a falsy value: Oct 12 05:38:32 bcik volumio[4960]: assert.ok(self.idling) Oct 12 05:38:32 bcik go-librespot[5152]: time="2026-10-12T05:38:32+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:32 bcik volumio[4960]: error: The expression evaluated to a falsy value: Oct 12 05:38:32 bcik volumio[4960]: assert.ok(self.idling) Oct 12 05:38:32 bcik volumio[4960]: info: MPD running with PID5121 Oct 12 05:38:32 bcik volumio[4960]: ,establishing connection Oct 12 05:38:32 bcik volumio[4960]: error: updateQueue error: null Oct 12 05:38:32 bcik volumio[4960]: error: updateQueue error: null Oct 12 05:38:32 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:32 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:35 bcik volumio-remote-updater[9031]: [2026-10-12 05:38:35] [connect] Successful connection Oct 12 05:38:35 bcik volumio-remote-updater[9031]: [2026-10-12 05:38:35] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1791776315 101 Oct 12 05:38:35 bcik volumio[4960]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 3 Oct 12 05:38:35 bcik volumio[4960]: info: go-librespot daemon successfully initialized Oct 12 05:38:36 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4589. Oct 12 05:38:36 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:36 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:36 bcik go-librespot[5197]: go-librespot daemon starting... Oct 12 05:38:36 bcik go-librespot[5198]: time="2026-10-12T05:38:36+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:36 bcik go-librespot[5198]: time="2026-10-12T05:38:36+02:00" level=debug msg="app state loaded" Oct 12 05:38:36 bcik go-librespot[5198]: time="2026-10-12T05:38:36+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:36 bcik go-librespot[5198]: time="2026-10-12T05:38:36+02: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]" Oct 12 05:38:36 bcik go-librespot[5198]: time="2026-10-12T05:38:36+02: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]" Oct 12 05:38:36 bcik go-librespot[5198]: time="2026-10-12T05:38:36+02: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]" Oct 12 05:38:36 bcik go-librespot[5198]: time="2026-10-12T05:38:36+02:00" level=info msg="zeroconf server listening on port 35397" Oct 12 05:38:36 bcik go-librespot[5198]: time="2026-10-12T05:38:36+02:00" level=debug msg="obtained new client token: AAFfJFnb5Nv53nOE4rjVXTh8E7k2T1aXHjdnBTYurQQ5u2aWm3M/Z7K5pjG/BQcW92bH4/0Mg7DcUhDxqC02+KOBx2dGQg/RchKgdgFv8i5FsUh2XPxAVm815gopyBbH2s6MvaHM/Za8gvfj6L88Im36ef6BebzlFVjHg9ALO8/S35/tWzBLPdUTqeglUSi3aEVGUFzzCTt+93Ct4w2rk08JtBPblPOU+fTO9L71lbuDuLu+vhQx" Oct 12 05:38:36 bcik go-librespot[5198]: time="2026-10-12T05:38:36+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:38:36 bcik go-librespot[5198]: time="2026-10-12T05:38:36+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:36 bcik go-librespot[5198]: time="2026-10-12T05:38:36+02:00" level=debug msg="completed challenge" Oct 12 05:38:36 bcik go-librespot[5198]: time="2026-10-12T05:38:36+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:36 bcik go-librespot[5198]: time="2026-10-12T05:38:36+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:36 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:36 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:37 bcik volumio[4960]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Oct 12 05:38:38 bcik volumio[4960]: info: Initializing connection to go-librespot Websocket Oct 12 05:38:38 bcik volumio[4960]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:38:39 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4590. Oct 12 05:38:39 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:39 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:39 bcik go-librespot[5208]: go-librespot daemon starting... Oct 12 05:38:39 bcik go-librespot[5209]: time="2026-10-12T05:38:39+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:39 bcik go-librespot[5209]: time="2026-10-12T05:38:39+02:00" level=debug msg="app state loaded" Oct 12 05:38:39 bcik go-librespot[5209]: time="2026-10-12T05:38:39+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:39 bcik go-librespot[5209]: time="2026-10-12T05:38:39+02: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]" Oct 12 05:38:39 bcik go-librespot[5209]: time="2026-10-12T05:38:39+02: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]" Oct 12 05:38:39 bcik go-librespot[5209]: time="2026-10-12T05:38:39+02: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]" Oct 12 05:38:39 bcik go-librespot[5209]: time="2026-10-12T05:38:39+02:00" level=info msg="zeroconf server listening on port 38581" Oct 12 05:38:39 bcik go-librespot[5209]: time="2026-10-12T05:38:39+02:00" level=debug msg="obtained new client token: AAEbiQtUo4ClEhLr7YzM33UPnkhN9SMTmrahwL84J31an1ixJ18n0hjp+X8XPs72/vIvOVbmJrRT/QP+chXSgh0gkQjuFkyJufjzDwNvgfgz3VJTIy+pvcgpB/2KdDjpE+C8UcXhLs1vlZzENfRbMCtVGK/w3RnkGytldvIuQp8T802tYPHziD78+XxTVJmOuRFDxxWHRTpVU/LpMtuAKdigKVAZOsHVC0s4koI/icR432p/9YRnEG8=" Oct 12 05:38:39 bcik go-librespot[5209]: time="2026-10-12T05:38:39+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:38:39 bcik go-librespot[5209]: time="2026-10-12T05:38:39+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:39 bcik go-librespot[5209]: time="2026-10-12T05:38:39+02:00" level=debug msg="completed challenge" Oct 12 05:38:39 bcik go-librespot[5209]: time="2026-10-12T05:38:39+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:39 bcik go-librespot[5209]: time="2026-10-12T05:38:39+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:39 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:39 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 12 05:38:41 bcik volumio[4960]: info: Adding plugin bluetooth to MyMusic Plugins Oct 12 05:38:41 bcik volumio[4960]: info: Adding plugin multiroom to MyMusic Plugins Oct 12 05:38:41 bcik volumio[4960]: info: Adding plugin metavolumio to MyMusic Plugins Oct 12 05:38:41 bcik volumio[4960]: info: Adding plugin cd_controller to MyMusic Plugins Oct 12 05:38:41 bcik volumio[4960]: info: Adding plugin qobuzconnect to MyMusic Plugins Oct 12 05:38:41 bcik volumio[4960]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 12 05:38:41 bcik volumio[4960]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 12 05:38:41 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:41 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:41 bcik volumio[4960]: info: Starting MyVolumio Remote Streaming Endpoints Oct 12 05:38:41 bcik volumio[4960]: info: MyVolumio login type: Token Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 12 05:38:41 bcik volumio[4960]: info: Streaming services startup Oct 12 05:38:41 bcik volumio[4960]: info: Starting Streaming Daemon Oct 12 05:38:41 bcik sudo[5233]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 12 05:38:41 bcik sudo[5233]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:41 bcik volumio[4960]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 12 05:38:41 bcik sudo[5233]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:41 bcik sudo[5240]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 05:38:41 bcik sudo[5240]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:41 bcik sudo[5240]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:41 bcik sudo[5242]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 05:38:41 bcik sudo[5242]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:41 bcik sudo[5242]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:41 bcik volumio[4960]: error: Cannot start Volumio Streaming Daemon Oct 12 05:38:41 bcik volumio[4960]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 12 05:38:41 bcik volumio[4960]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 12 05:38:41 bcik sudo[5246]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 12 05:38:41 bcik sudo[5246]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:41 bcik sudo[5246]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:41 bcik volumio[4960]: info: Upmpdcli Daemon Started Oct 12 05:38:41 bcik volumio[4960]: info: Initializing connection to go-librespot Websocket Oct 12 05:38:41 bcik volumio[4960]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:38:42 bcik volumio[4960]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 12 05:38:42 bcik volumio[4960]: info: MyVolumio token set successfully Oct 12 05:38:42 bcik volumio[4960]: info: MYVOLUMIO: Adding device Oct 12 05:38:42 bcik volumio[4960]: info: MYVOLUMIO: Evaluating Server Oct 12 05:38:42 bcik volumio[4960]: info: MyVolumio status changed Oct 12 05:38:42 bcik volumio[4960]: info: Streaming services startup Oct 12 05:38:42 bcik volumio[4960]: info: Starting Streaming Daemon Oct 12 05:38:42 bcik volumio[4960]: info: Removing browser output: myVolumio user plan is not superstar Oct 12 05:38:42 bcik volumio[4960]: info: Removing audio output: Oct 12 05:38:42 bcik volumio[4960]: info: Stoppping Tunnel 1 Oct 12 05:38:42 bcik sudo[5270]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 12 05:38:42 bcik sudo[5270]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:42 bcik sudo[5272]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Oct 12 05:38:42 bcik sudo[5272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:42 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:38:42 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:38:42 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:38:42 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:38:42 bcik sudo[5270]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:42 bcik volumio[4960]: error: Cannot start Volumio Streaming Daemon Oct 12 05:38:42 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:38:42 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:38:42 bcik volumio[4960]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 12 05:38:42 bcik volumio[4960]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 12 05:38:42 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:38:42 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:38:42 bcik sudo[5272]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:42 bcik volumio[4960]: info: Remote SSH Stopped Oct 12 05:38:42 bcik volumio[4960]: info: Setting Geolocation for MyVolumio to eu6 Oct 12 05:38:42 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:42 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:42 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:43 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4591. Oct 12 05:38:43 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:43 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:43 bcik go-librespot[5275]: go-librespot daemon starting... Oct 12 05:38:43 bcik go-librespot[5276]: time="2026-10-12T05:38:43+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:43 bcik go-librespot[5276]: time="2026-10-12T05:38:43+02:00" level=debug msg="app state loaded" Oct 12 05:38:43 bcik go-librespot[5276]: time="2026-10-12T05:38:43+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:43 bcik go-librespot[5276]: time="2026-10-12T05:38:43+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 05:38:43 bcik go-librespot[5276]: time="2026-10-12T05:38:43+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 05:38:43 bcik go-librespot[5276]: time="2026-10-12T05:38:43+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 05:38:43 bcik go-librespot[5276]: time="2026-10-12T05:38:43+02:00" level=info msg="zeroconf server listening on port 35877" Oct 12 05:38:43 bcik volumio[4960]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 12 05:38:43 bcik volumio[4960]: info: Updating MyVolumio device info Oct 12 05:38:43 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:43 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:43 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:44 bcik volumio[4960]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 12 05:38:44 bcik volumio[4960]: info: Initializing connection to go-librespot Websocket Oct 12 05:38:44 bcik go-librespot[5276]: time="2026-10-12T05:38:44+02:00" level=debug msg="new websocket client" Oct 12 05:38:44 bcik volumio[4960]: info: Connection to go-librespot Websocket established Oct 12 05:38:47 bcik volumio[4960]: info: MYVOLUMIO: Adding device Oct 12 05:38:47 bcik volumio[4960]: info: MYVOLUMIO: Evaluating Server Oct 12 05:38:47 bcik volumio[4960]: info: Setting Geolocation for MyVolumio to eu6 Oct 12 05:38:47 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:47 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:47 bcik volumio[4960]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:47 bcik volumio[4960]: info: Getting Spotify volume Oct 12 05:38:47 bcik volumio[4960]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Oct 12 05:38:47 bcik volumio[4960]: info: CoreCommandRouter::volumioGetState Oct 12 05:38:47 bcik volumio[4960]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:47 bcik volumio[4960]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Oct 12 05:38:47 bcik volumio[4960]: SPOTIFY: SPOTIFY VOLUME undefined Oct 12 05:38:47 bcik volumio[4960]: SPOTIFY: VOLUMIO VOLUME 41 Oct 12 05:38:47 bcik volumio[4960]: info: Aligning Spotify Volume to Volumio Volume Oct 12 05:38:47 bcik volumio[4960]: info: CoreCommandRouter::volumioGetState Oct 12 05:38:47 bcik volumio[4960]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:47 bcik volumio[4960]: info: Setting Spotify Volume from Volumio: 41 Oct 12 05:38:47 bcik go-librespot[5276]: time="2026-10-12T05:38:47+02:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: invalid status code from clienttoken: 503" Oct 12 05:38:47 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:47 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:47 bcik volumio[4960]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 05:38:47 bcik volumio[4960]: Error: socket hang up Oct 12 05:38:47 bcik volumio[4960]: at connResetException (node:internal/errors:720:14) Oct 12 05:38:47 bcik volumio[4960]: at Socket.socketOnEnd (node:_http_client:519:23) Oct 12 05:38:47 bcik volumio[4960]: at Socket.emit (node:events:526:35) Oct 12 05:38:47 bcik volumio[4960]: at endReadableNT (node:internal/streams/readable:1376:12) Oct 12 05:38:47 bcik volumio[4960]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Oct 12 05:38:47 bcik volumio[4960]: code: 'ECONNRESET', Oct 12 05:38:47 bcik volumio[4960]: response: undefined Oct 12 05:38:47 bcik volumio[4960]: } Oct 12 05:38:47 bcik volumio[4960]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 05:38:47 bcik sudo[5317]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-12 05:37' Oct 12 05:38:47 bcik sudo[5317]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:48 bcik sudo[5317]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:48 bcik volumio-remote-updater[9031]: [2026-10-12 05:38:48] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Oct 12 05:38:48 bcik volumio-remote-updater[9031]: [2026-10-12 05:38:48] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Oct 12 05:38:48 bcik volumio5-onboarding[1483]: time=2026-10-12T05:38:48.397+02:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Oct 12 05:38:48 bcik volumio5-onboarding[1483]: time=2026-10-12T05:38:48.399+02:00 level=WARN msg="reconnection attempt failed" error="read tcp 127.0.0.1:41032->127.0.0.1:3000: read: connection reset by peer" Oct 12 05:38:48 bcik systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:48 bcik systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 12 05:38:48 bcik systemd[1]: volumio.service: Consumed 5.947s CPU time. Oct 12 05:38:48 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 12 05:38:48 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Oct 12 05:38:48 bcik systemd[1]: volumio.service: Scheduled restart job, restart counter is at 21820. Oct 12 05:38:48 bcik systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 12 05:38:48 bcik systemd[1]: Stopped volumio.service - Volumio Backend Module. Oct 12 05:38:48 bcik systemd[1]: volumio.service: Consumed 5.947s CPU time. Oct 12 05:38:48 bcik systemd[1]: Started volumio.service - Volumio Backend Module. Oct 12 05:38:48 bcik systemd[1]: dynamicswap.service: Deactivated successfully. Oct 12 05:38:48 bcik volumio[5340]: info: ------------------------------------------- Oct 12 05:38:48 bcik volumio[5340]: info: ----- Volumio3 ---- Oct 12 05:38:48 bcik volumio[5340]: info: ------------------------------------------- Oct 12 05:38:48 bcik volumio[5340]: info: ----- System startup ---- Oct 12 05:38:48 bcik volumio[5340]: info: ------------------------------------------- Oct 12 05:38:49 bcik volumio[5340]: info: MYVOLUMIO Environment detected Oct 12 05:38:49 bcik volumio[5340]: info: Plugin folders cleanup Oct 12 05:38:49 bcik volumio[5340]: info: Scanning into folder /volumio/app/plugins/ Oct 12 05:38:49 bcik volumio[5340]: info: Scanning category audio_interface Oct 12 05:38:49 bcik volumio[5340]: info: Scanning category miscellanea Oct 12 05:38:49 bcik volumio[5340]: info: Scanning category music_service Oct 12 05:38:49 bcik volumio[5340]: info: Scanning category plugins.json Oct 12 05:38:49 bcik volumio[5340]: info: Scanning category system_controller Oct 12 05:38:49 bcik volumio[5340]: info: Scanning category user_interface Oct 12 05:38:49 bcik volumio[5340]: info: Scanning into folder /data/plugins/ Oct 12 05:38:49 bcik volumio[5340]: info: Scanning category music_service Oct 12 05:38:49 bcik volumio[5340]: info: Plugin folders cleanup completed Oct 12 05:38:49 bcik volumio[5340]: info: ------------------------------------------- Oct 12 05:38:49 bcik volumio[5340]: info: ----- Core plugins startup ---- Oct 12 05:38:49 bcik volumio[5340]: info: ------------------------------------------- Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugins from folder /volumio/app/plugins/ Oct 12 05:38:49 bcik volumio[5340]: info: Adding plugin upnp to MyMusic Plugins Oct 12 05:38:49 bcik volumio[5340]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 12 05:38:49 bcik volumio[5340]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugins from folder /data/plugins/ Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugin "system"... Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugin "appearance"... Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugin "network"... Oct 12 05:38:49 bcik volumio[5340]: info: Refreshing Cached IP Addresses Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugin "services"... Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugin "volumio5onboarding"... Oct 12 05:38:49 bcik sudo[5368]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 05:38:49 bcik sudo[5370]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 05:38:49 bcik sudo[5368]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:49 bcik sudo[5370]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugin "alsa_controller"... Oct 12 05:38:49 bcik sudo[5368]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:49 bcik sudo[5370]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:49 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugin "wizard"... Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugin "networkfs"... Oct 12 05:38:49 bcik volumio[5340]: info: Starting Udev Watcher for removable devices Oct 12 05:38:49 bcik volumio[5340]: info: Ignoring mount for partition: boot Oct 12 05:38:49 bcik volumio[5340]: info: Ignoring mount for partition: volumio Oct 12 05:38:49 bcik volumio[5340]: info: Ignoring mount for partition: volumio_data Oct 12 05:38:49 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugin "volumio_command_line_client"... Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugin "upnp"... Oct 12 05:38:49 bcik volumio[5340]: info: [1791776329344] Starting Upmpd Daemon Oct 12 05:38:49 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugin "my_music"... Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugin "mpd"... Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugin "upnp_browser"... Oct 12 05:38:49 bcik volumio[5340]: info: Starting UPNP Browser Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugin "alarm-clock"... Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugin "airplay_emulation"... Oct 12 05:38:49 bcik volumio[5340]: info: Starting Shairport Sync Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugin "last_100"... Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugin "webradio"... Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugin "i2s_dacs"... Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugin "volumiodiscovery"... Oct 12 05:38:49 bcik volumio[5340]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 12 05:38:49 bcik volumio[5340]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 05:38:49 bcik volumio[5340]: *** WARNING *** For more information see Oct 12 05:38:49 bcik volumio[5340]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 12 05:38:49 bcik volumio[5340]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 05:38:49 bcik volumio[5340]: *** WARNING *** For more information see Oct 12 05:38:49 bcik node[5340]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 12 05:38:49 bcik node[5340]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 05:38:49 bcik node[5340]: *** WARNING *** For more information see Oct 12 05:38:49 bcik node[5340]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 12 05:38:49 bcik node[5340]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 12 05:38:49 bcik node[5340]: *** WARNING *** For more information see Oct 12 05:38:49 bcik volumio[5340]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 12 05:38:49 bcik volumio[5340]: info: Discovery: Started advertising with name: Bącik Oct 12 05:38:49 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugin "spop"... Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugin "outputs"... Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugin "albumart"... Oct 12 05:38:49 bcik volumio[5340]: info: Plugin example_plugin is not enabled Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugin "inputs"... Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugin "updater_comm"... Oct 12 05:38:49 bcik volumio[5340]: info: Plugin mpdemulation is not enabled Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugin "rest_api"... Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugin "websocket"... Oct 12 05:38:49 bcik volumio[5340]: info: Starting Socket.io Server version 1.7.4 Oct 12 05:38:49 bcik volumio[5340]: info: Loading plugin "radio_browser"... Oct 12 05:38:50 bcik volumio[5400]: Forking 3 albumart workers Oct 12 05:38:50 bcik volumio[5340]: info: Loading i18n strings for locale pl Oct 12 05:38:50 bcik volumio[5340]: Updating browse sources language Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::initPlayerControls Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: Express server listening on port 3000 Oct 12 05:38:50 bcik volumio[5340]: [Metrics] WebUI: 1s 262.24ms Oct 12 05:38:50 bcik volumio[5340]: info: CoreStateMachine::resetVolumioState Oct 12 05:38:50 bcik volumio[5340]: info: CoreStateMachine::getcurrentVolume Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::volumioRetrievevolume Oct 12 05:38:50 bcik volumio[5340]: info: Volumio Network Manager: Network status updated: 1 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: Reloading queue from file Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:38:50 bcik volumio[5340]: info: CoreStateMachine::setRepeat false single undefined Oct 12 05:38:50 bcik volumio[5340]: info: CoreStateMachine::pushState Oct 12 05:38:50 bcik volumio[5340]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::volumioPushState Oct 12 05:38:50 bcik volumio[5340]: info: CoreStateMachine::setRandom false Oct 12 05:38:50 bcik volumio[5340]: info: CoreStateMachine::pushState Oct 12 05:38:50 bcik volumio[5340]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::volumioPushState Oct 12 05:38:50 bcik volumio[5340]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 12 05:38:50 bcik volumio[5340]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04171 Oct 12 05:38:50 bcik volumio[5340]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 12 05:38:50 bcik volumio[5340]: info: VolumeController:: Volume=41 Mute =false Oct 12 05:38:50 bcik volumio[5340]: info: CoreStateMachine::pushState Oct 12 05:38:50 bcik volumio[5340]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::volumioPushState Oct 12 05:38:50 bcik volumio[5340]: info: CoreStateMachine::updateTrackBlock Oct 12 05:38:50 bcik volumio[5340]: info: CorePlayQueue::getTrackBlock Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::volumioRetrievevolume Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:38:50 bcik volumio[5340]: info: Setting Device type: Raspberry PI Oct 12 05:38:50 bcik volumio[5340]: info: Completed loading Core Plugins Oct 12 05:38:50 bcik volumio[5340]: info: Preparing to generate the ALSA configuration file Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:38:50 bcik volumio[5340]: info: Asound.conf file unchanged, so no further update is needed Oct 12 05:38:50 bcik volumio[5340]: info: Output device has changed, restarting MPD Oct 12 05:38:50 bcik volumio[5340]: info: Output device has changed, restarting Shairport Sync Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:50 bcik sudo[5454]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 12 05:38:50 bcik sudo[5454]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:50 bcik sudo[5454]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:50 bcik volumio[5340]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 05:38:50 bcik volumio[5340]: info: ___________ START PLUGINS ___________ Oct 12 05:38:50 bcik sudo[5461]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 12 05:38:50 bcik sudo[5461]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:50 bcik volumio[5340]: info: ControllerMpd::onStart: Initializing MPD Oct 12 05:38:50 bcik volumio[5340]: info: Creating MPD Configuration file Oct 12 05:38:50 bcik sudo[5463]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Oct 12 05:38:50 bcik sudo[5463]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 05:38:50 bcik volumio[5340]: info: [1791776330263] CoreMusicLibrary::Adding element Serwery Mediów Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:38:50 bcik sudo[5467]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 12 05:38:50 bcik sudo[5467]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:50 bcik systemd[1]: Stopping mpd.service - Music Player Daemon... Oct 12 05:38:50 bcik volumio[5340]: info: UPNP Browser: Client initialized successfully Oct 12 05:38:50 bcik sudo[5467]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:50 bcik sudo[5463]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:50 bcik sudo[5469]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 12 05:38:50 bcik sudo[5469]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:50 bcik systemd[1]: mpd.service: Deactivated successfully. Oct 12 05:38:50 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 12 05:38:50 bcik systemd[1]: mpd.socket: Deactivated successfully. Oct 12 05:38:50 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 12 05:38:50 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 12 05:38:50 bcik volumio[5340]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 05:38:50 bcik volumio[5340]: info: [1791776330329] CoreMusicLibrary::Adding element Last_100 Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 05:38:50 bcik volumio[5340]: info: [1791776330330] CoreMusicLibrary::Adding element Webradio Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 05:38:50 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 12 05:38:50 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Oct 12 05:38:50 bcik volumio[5340]: info: Initializing BBC Radios Oct 12 05:38:50 bcik systemd[1]: mpd.service: Deactivated successfully. Oct 12 05:38:50 bcik systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 12 05:38:50 bcik systemd[1]: mpd.socket: Deactivated successfully. Oct 12 05:38:50 bcik systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 12 05:38:50 bcik systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 12 05:38:50 bcik systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 12 05:38:50 bcik systemd[1]: Starting mpd.service - Music Player Daemon... Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:50 bcik volumio[5412]: Starting albumart workers Oct 12 05:38:50 bcik volumio[5340]: info: Creating Spotify config file Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik sudo[5486]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 12 05:38:50 bcik sudo[5486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 12 05:38:50 bcik sudo[5486]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:50 bcik volumio[5411]: Starting albumart workers Oct 12 05:38:50 bcik volumio[5410]: Starting albumart workers Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 12 05:38:50 bcik volumio[5340]: info: [1791776330525] CoreMusicLibrary::Adding element Radio Browser Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 05:38:50 bcik volumio[5340]: Cannot find translation for source Radio Browser Oct 12 05:38:50 bcik volumio[5340]: info: Volumio Calling Home Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Oct 12 05:38:50 bcik volumio[5340]: info: VolumeController:: Volume=41 Mute =false Oct 12 05:38:50 bcik volumio[5340]: info: CoreStateMachine::pushState Oct 12 05:38:50 bcik volumio[5340]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::volumioPushState Oct 12 05:38:50 bcik volumio[5340]: info: MPD Permissions set Oct 12 05:38:50 bcik volumio[5340]: info: MPD Permissions set Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Oct 12 05:38:50 bcik volumio[5340]: info: Spotify config file written Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik sudo[5509]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 12 05:38:50 bcik sudo[5509]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 12 05:38:50 bcik volumio[5340]: info: No need to fix Spotify hosts Oct 12 05:38:50 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:50 bcik go-librespot[5522]: go-librespot daemon starting... Oct 12 05:38:50 bcik sudo[5509]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:50 bcik go-librespot[5528]: time="2026-10-12T05:38:50+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:50 bcik go-librespot[5528]: time="2026-10-12T05:38:50+02:00" level=debug msg="app state loaded" Oct 12 05:38:50 bcik go-librespot[5528]: time="2026-10-12T05:38:50+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:50 bcik volumio[5340]: info: Volumio called home Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: info: Starting Shairport Sync Oct 12 05:38:50 bcik volumio[5340]: info: Starting Shairport Sync Oct 12 05:38:50 bcik sudo[5541]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 12 05:38:50 bcik sudo[5541]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:50 bcik volumio[5340]: info: Starting Shairport Sync Oct 12 05:38:50 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 12 05:38:50 bcik sudo[5544]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 12 05:38:50 bcik sudo[5544]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:50 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Oct 12 05:38:50 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 12 05:38:50 bcik systemd[1]: shairport-sync.service: Consumed 1.529s CPU time. Oct 12 05:38:50 bcik sudo[5548]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 12 05:38:50 bcik sudo[5548]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 12 05:38:50 bcik sudo[5541]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:50 bcik systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 12 05:38:50 bcik systemd[1]: shairport-sync.service: Deactivated successfully. Oct 12 05:38:50 bcik systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 12 05:38:50 bcik go-librespot[5528]: time="2026-10-12T05:38:50+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 05:38:50 bcik go-librespot[5528]: time="2026-10-12T05:38:50+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 05:38:50 bcik go-librespot[5528]: time="2026-10-12T05:38:50+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 05:38:50 bcik volumio[5340]: info: An error occurred while refreshing Spotify Token Error: Bad Request Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 12 05:38:50 bcik go-librespot[5528]: time="2026-10-12T05:38:50+02:00" level=info msg="zeroconf server listening on port 42423" Oct 12 05:38:50 bcik sudo[5544]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:50 bcik sudo[5548]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::volumioGetState Oct 12 05:38:50 bcik volumio[5340]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:50 bcik volumio[5340]: info: Shairport-Sync Started Oct 12 05:38:50 bcik volumio[5340]: Error adding Membership: Error: addMembership EINVAL Oct 12 05:38:50 bcik volumio[5340]: info: Shairport-Sync Started Oct 12 05:38:50 bcik volumio[5340]: info: Shairport-Sync Started Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: info: Discovery: adding f1ed5fb6-e21d-47c8-819b-29842600355e Oct 12 05:38:50 bcik volumio[5340]: info: Discovery: Found device Bącik Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::volumioGetState Oct 12 05:38:50 bcik volumio[5340]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:50 bcik volumio[5340]: info: Discovery: this is already registered, f1ed5fb6-e21d-47c8-819b-29842600355e Oct 12 05:38:50 bcik volumio[5340]: info: Discovery: Found device Bącik Oct 12 05:38:50 bcik volumio[5340]: info: CoreCommandRouter::volumioGetState Oct 12 05:38:50 bcik volumio[5340]: info: CorePlayQueue::getTrack 0 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik go-librespot[5528]: time="2026-10-12T05:38:50+02:00" level=debug msg="obtained new client token: AAEAUMYQLKUAcj3V7GddwqjgJANMLaRvlYT1CGxdVPAsczPV/sbfh/keCDDLVRuLAbw1V1827rdqxdMhX2U6yJxqzgRk+cvCxPeRZq6JDNo/W3NFCpYJ3dDuBl4oIkNgceHEBupLY1Nwca3ZBUxQsyhLPNIT+V7SDUdFAcbFrcyoZbVV6R5NFDOAKCzcHGOU3K86hDl5df4jsm94CfO88pYvAiXDglCzcCTBog+cVncmqJDZCso28KA=" Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik go-librespot[5528]: time="2026-10-12T05:38:50+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik go-librespot[5528]: time="2026-10-12T05:38:50+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:50 bcik go-librespot[5528]: time="2026-10-12T05:38:50+02:00" level=debug msg="completed challenge" Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik go-librespot[5528]: time="2026-10-12T05:38:50+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Oct 12 05:38:50 bcik mpd[5498]: 2026-10-12T05:38:50 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 12 05:38:50 bcik systemd[1]: Started mpd.service - Music Player Daemon. Oct 12 05:38:50 bcik sudo[5461]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:50 bcik sudo[5469]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:50 bcik volumio[5340]: error: updateQueue error: null Oct 12 05:38:51 bcik volumio[5340]: info: Completed starting Core Plugins Oct 12 05:38:51 bcik volumio[5340]: info: ------------------------------------------- Oct 12 05:38:51 bcik volumio[5340]: info: ----- MyVolumio plugins startup ---- Oct 12 05:38:51 bcik volumio[5340]: info: ------------------------------------------- Oct 12 05:38:51 bcik volumio[5340]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 12 05:38:51 bcik volumio[5340]: error: updateQueue error: null Oct 12 05:38:51 bcik go-librespot[5528]: time="2026-10-12T05:38:51+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:51 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:51 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:51 bcik volumio[5340]: info: MPD running with PID5498 Oct 12 05:38:51 bcik volumio[5340]: ,establishing connection Oct 12 05:38:51 bcik volumio[5340]: error: updateQueue error: null Oct 12 05:38:53 bcik volumio-remote-updater[9031]: [2026-10-12 05:38:53] [connect] Successful connection Oct 12 05:38:53 bcik volumio-remote-updater[9031]: [2026-10-12 05:38:53] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1791776333 101 Oct 12 05:38:53 bcik volumio[5340]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 3 Oct 12 05:38:53 bcik volumio[5340]: info: go-librespot daemon successfully initialized Oct 12 05:38:54 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4592. Oct 12 05:38:54 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:54 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:54 bcik go-librespot[5575]: go-librespot daemon starting... Oct 12 05:38:54 bcik go-librespot[5576]: time="2026-10-12T05:38:54+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:54 bcik go-librespot[5576]: time="2026-10-12T05:38:54+02:00" level=debug msg="app state loaded" Oct 12 05:38:54 bcik go-librespot[5576]: time="2026-10-12T05:38:54+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:54 bcik go-librespot[5576]: time="2026-10-12T05:38:54+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 05:38:54 bcik go-librespot[5576]: time="2026-10-12T05:38:54+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 05:38:54 bcik go-librespot[5576]: time="2026-10-12T05:38:54+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 05:38:54 bcik go-librespot[5576]: time="2026-10-12T05:38:54+02:00" level=info msg="zeroconf server listening on port 36627" Oct 12 05:38:54 bcik go-librespot[5576]: time="2026-10-12T05:38:54+02:00" level=debug msg="obtained new client token: AAF9cH8KpSkhzka8ZsW6956ZJL+J9tRa1xetY4q2ts0sTaA5ESht9uT2OJ3wxQjNkMVYdp3RUSEqdLhoi7hhVdy9YwPUi2J8V0LV+ZC0E0qFOMB93WXQHlWYZnTP06rrnYr1kt4OZlyBqsKjEapUL4zrNFmyNhIb3GTvp+UoD5y0qnfhezflLUoSV1Tn/iL0ksSecBtL/n4vg34f/ARhQCeAPjD1GGFAErBiDPtoy0HRYZmusa8a" Oct 12 05:38:54 bcik go-librespot[5576]: time="2026-10-12T05:38:54+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Oct 12 05:38:54 bcik go-librespot[5576]: time="2026-10-12T05:38:54+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Oct 12 05:38:54 bcik go-librespot[5576]: time="2026-10-12T05:38:54+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:54 bcik go-librespot[5576]: time="2026-10-12T05:38:54+02:00" level=debug msg="completed challenge" Oct 12 05:38:54 bcik go-librespot[5576]: time="2026-10-12T05:38:54+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:54 bcik go-librespot[5576]: time="2026-10-12T05:38:54+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:54 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:54 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:55 bcik volumio[5340]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Oct 12 05:38:56 bcik volumio[5340]: info: Initializing connection to go-librespot Websocket Oct 12 05:38:56 bcik volumio[5340]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:38:57 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4593. Oct 12 05:38:57 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:57 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:38:57 bcik go-librespot[5585]: go-librespot daemon starting... Oct 12 05:38:57 bcik go-librespot[5586]: time="2026-10-12T05:38:57+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:38:57 bcik go-librespot[5586]: time="2026-10-12T05:38:57+02:00" level=debug msg="app state loaded" Oct 12 05:38:57 bcik go-librespot[5586]: time="2026-10-12T05:38:57+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:38:57 bcik go-librespot[5586]: time="2026-10-12T05:38:57+02: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]" Oct 12 05:38:57 bcik go-librespot[5586]: time="2026-10-12T05:38:57+02: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]" Oct 12 05:38:57 bcik go-librespot[5586]: time="2026-10-12T05:38:57+02: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]" Oct 12 05:38:57 bcik go-librespot[5586]: time="2026-10-12T05:38:57+02:00" level=info msg="zeroconf server listening on port 33433" Oct 12 05:38:57 bcik go-librespot[5586]: time="2026-10-12T05:38:57+02:00" level=debug msg="obtained new client token: AAFW93mwkPbUiG/ydHa6XJr5l/IcOPoHFpv9s5v8THZf7GtQi/avou12hVif117LbhqnBUk+9Xo5o8NBoUCicylhaXQ5N1/Jn/J0BCm11kS3L5tXf0DsFLvJFWGtPSjRMcpP4fJOy6i5LqX715JJB5YxCnQ3SCpazf/HmnXg+/VCIQTa3K1a7x3KGfSjQDA8yQT2AT9ay9rWCFE91m3YkcR/a2Cp6yiAAKfqEzFjtEzGyAcSZ0uBmAg=" Oct 12 05:38:57 bcik go-librespot[5586]: time="2026-10-12T05:38:57+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:38:57 bcik go-librespot[5586]: time="2026-10-12T05:38:57+02:00" level=debug msg="completed keyexchange" Oct 12 05:38:57 bcik go-librespot[5586]: time="2026-10-12T05:38:57+02:00" level=debug msg="completed challenge" Oct 12 05:38:57 bcik go-librespot[5586]: time="2026-10-12T05:38:57+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:38:57 bcik go-librespot[5586]: time="2026-10-12T05:38:57+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:38:57 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:38:57 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 12 05:38:59 bcik volumio[5340]: info: Adding plugin bluetooth to MyMusic Plugins Oct 12 05:38:59 bcik volumio[5340]: info: Adding plugin multiroom to MyMusic Plugins Oct 12 05:38:59 bcik volumio[5340]: info: Adding plugin metavolumio to MyMusic Plugins Oct 12 05:38:59 bcik volumio[5340]: info: Adding plugin cd_controller to MyMusic Plugins Oct 12 05:38:59 bcik volumio[5340]: info: Adding plugin qobuzconnect to MyMusic Plugins Oct 12 05:38:59 bcik volumio[5340]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 12 05:38:59 bcik volumio[5340]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 12 05:38:59 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:59 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:38:59 bcik volumio[5340]: info: Starting MyVolumio Remote Streaming Endpoints Oct 12 05:38:59 bcik volumio[5340]: info: MyVolumio login type: Token Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 12 05:38:59 bcik volumio[5340]: info: Streaming services startup Oct 12 05:38:59 bcik volumio[5340]: info: Starting Streaming Daemon Oct 12 05:38:59 bcik sudo[5611]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 12 05:38:59 bcik volumio[5340]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 12 05:38:59 bcik sudo[5611]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:59 bcik sudo[5611]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:59 bcik sudo[5618]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 05:38:59 bcik sudo[5618]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:59 bcik volumio[5340]: error: Cannot start Volumio Streaming Daemon Oct 12 05:38:59 bcik volumio[5340]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 12 05:38:59 bcik volumio[5340]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 12 05:38:59 bcik sudo[5620]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 05:38:59 bcik sudo[5620]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:59 bcik sudo[5618]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:59 bcik sudo[5620]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:59 bcik sudo[5624]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 12 05:38:59 bcik sudo[5624]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:38:59 bcik sudo[5624]: pam_unix(sudo:session): session closed for user root Oct 12 05:38:59 bcik volumio[5340]: info: Upmpdcli Daemon Started Oct 12 05:38:59 bcik volumio[5340]: info: Initializing connection to go-librespot Websocket Oct 12 05:38:59 bcik volumio[5340]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:39:00 bcik volumio[5340]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 12 05:39:00 bcik volumio[5340]: info: MyVolumio token set successfully Oct 12 05:39:00 bcik volumio[5340]: info: MYVOLUMIO: Adding device Oct 12 05:39:00 bcik volumio[5340]: info: MYVOLUMIO: Evaluating Server Oct 12 05:39:00 bcik volumio[5340]: info: MyVolumio status changed Oct 12 05:39:00 bcik volumio[5340]: info: Streaming services startup Oct 12 05:39:00 bcik volumio[5340]: info: Starting Streaming Daemon Oct 12 05:39:00 bcik volumio[5340]: info: Removing browser output: myVolumio user plan is not superstar Oct 12 05:39:00 bcik volumio[5340]: info: Removing audio output: Oct 12 05:39:00 bcik volumio[5340]: info: Stoppping Tunnel 1 Oct 12 05:39:00 bcik sudo[5647]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 12 05:39:00 bcik sudo[5647]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:39:00 bcik sudo[5649]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Oct 12 05:39:00 bcik sudo[5649]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 12 05:39:00 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:39:00 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:39:00 bcik sudo[5647]: pam_unix(sudo:session): session closed for user root Oct 12 05:39:00 bcik volumio[5340]: error: Cannot start Volumio Streaming Daemon Oct 12 05:39:00 bcik volumio[5340]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 12 05:39:00 bcik volumio[5340]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 12 05:39:00 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:39:00 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:39:00 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:39:00 bcik systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 12 05:39:00 bcik sudo[5649]: pam_unix(sudo:session): session closed for user root Oct 12 05:39:00 bcik volumio[5340]: info: Remote SSH Stopped Oct 12 05:39:00 bcik volumio[5340]: info: Setting Geolocation for MyVolumio to eu6 Oct 12 05:39:00 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:39:00 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:39:00 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:39:01 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4594. Oct 12 05:39:01 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:39:01 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:39:01 bcik go-librespot[5652]: go-librespot daemon starting... Oct 12 05:39:01 bcik go-librespot[5653]: time="2026-10-12T05:39:01+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:39:01 bcik go-librespot[5653]: time="2026-10-12T05:39:01+02:00" level=debug msg="app state loaded" Oct 12 05:39:01 bcik go-librespot[5653]: time="2026-10-12T05:39:01+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:39:01 bcik volumio[5340]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 12 05:39:01 bcik go-librespot[5653]: time="2026-10-12T05:39:01+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 05:39:01 bcik go-librespot[5653]: time="2026-10-12T05:39:01+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 05:39:01 bcik go-librespot[5653]: time="2026-10-12T05:39:01+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 05:39:01 bcik go-librespot[5653]: time="2026-10-12T05:39:01+02:00" level=info msg="zeroconf server listening on port 36773" Oct 12 05:39:01 bcik go-librespot[5653]: time="2026-10-12T05:39:01+02:00" level=debug msg="obtained new client token: AAH047b0SqebBpTlP7C5wwA60iln9M1Tfi3wKJb04jEpKjgytG9igKlDyxgl2a6CgEM2wCumhYZFPelW5FdqdvfAM+l7uc2+JoxMyEIhnjViA7moyuRoeo56L98/pt+TYPsSWIEerscpA6J2Isrpp8yXfNWGrIRZuqlrQjEF94BJzGwg6+LE5hli0U7sBatRg4TOLHvrjUcA7oisAWErZSWTbpjc9Lk7NhtBJuOxVOA2DBUJV/uF" Oct 12 05:39:01 bcik go-librespot[5653]: time="2026-10-12T05:39:01+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:39:01 bcik go-librespot[5653]: time="2026-10-12T05:39:01+02:00" level=debug msg="completed keyexchange" Oct 12 05:39:01 bcik go-librespot[5653]: time="2026-10-12T05:39:01+02:00" level=debug msg="completed challenge" Oct 12 05:39:01 bcik go-librespot[5653]: time="2026-10-12T05:39:01+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:39:01 bcik go-librespot[5653]: time="2026-10-12T05:39:01+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:39:01 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:39:01 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:39:01 bcik volumio[5340]: info: Updating MyVolumio device info Oct 12 05:39:01 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:39:01 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:39:01 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:39:02 bcik volumio[5340]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 12 05:39:02 bcik volumio[5340]: info: Initializing connection to go-librespot Websocket Oct 12 05:39:02 bcik volumio[5340]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:39:04 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4595. Oct 12 05:39:04 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:39:04 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:39:04 bcik go-librespot[5662]: go-librespot daemon starting... Oct 12 05:39:04 bcik go-librespot[5663]: time="2026-10-12T05:39:04+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:39:04 bcik go-librespot[5663]: time="2026-10-12T05:39:04+02:00" level=debug msg="app state loaded" Oct 12 05:39:04 bcik go-librespot[5663]: time="2026-10-12T05:39:04+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:39:04 bcik go-librespot[5663]: time="2026-10-12T05:39:04+02: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]" Oct 12 05:39:04 bcik go-librespot[5663]: time="2026-10-12T05:39:04+02: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]" Oct 12 05:39:04 bcik go-librespot[5663]: time="2026-10-12T05:39:04+02: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]" Oct 12 05:39:04 bcik go-librespot[5663]: time="2026-10-12T05:39:04+02:00" level=info msg="zeroconf server listening on port 46757" Oct 12 05:39:04 bcik go-librespot[5663]: time="2026-10-12T05:39:04+02:00" level=debug msg="obtained new client token: AAHpayYlH3ZLuwrbL3QN5TyFoUsrrde9bdvk+4oqnTq9k9OHbQV0YOBbZLk0E2buJpJvhaLx3NMB4s41sxI/KCwawB8F7Etjn77M/AM64XykGuczTtBZFueJJoamfzZbqnn/bff3UoPvteOJD4Kr6STbwgg+3dyFSZOZmQOKVGCdfraOuq9amaaM4sxPuQE+7dmY1R+HYCtrHT1OnhKrpdrw8h6DFgWzuz9UiAI5URgNlXTczAYwkfs=" Oct 12 05:39:04 bcik go-librespot[5663]: time="2026-10-12T05:39:04+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:39:04 bcik go-librespot[5663]: time="2026-10-12T05:39:04+02:00" level=debug msg="completed keyexchange" Oct 12 05:39:04 bcik go-librespot[5663]: time="2026-10-12T05:39:04+02:00" level=debug msg="completed challenge" Oct 12 05:39:04 bcik go-librespot[5663]: time="2026-10-12T05:39:04+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:39:04 bcik go-librespot[5663]: time="2026-10-12T05:39:04+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:39:04 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:39:04 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:39:05 bcik volumio[5340]: info: MYVOLUMIO: Adding device Oct 12 05:39:05 bcik volumio[5340]: info: MYVOLUMIO: Evaluating Server Oct 12 05:39:05 bcik volumio[5340]: info: Setting Geolocation for MyVolumio to eu6 Oct 12 05:39:05 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:39:05 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:39:05 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:39:05 bcik volumio[5340]: info: Initializing connection to go-librespot Websocket Oct 12 05:39:05 bcik volumio[5340]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:39:05 bcik volumio[5340]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 12 05:39:06 bcik volumio[5340]: info: Updating MyVolumio device info Oct 12 05:39:06 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:39:06 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:39:06 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 12 05:39:07 bcik volumio[5340]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 12 05:39:08 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4596. Oct 12 05:39:08 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:39:08 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:39:08 bcik go-librespot[5690]: go-librespot daemon starting... Oct 12 05:39:08 bcik go-librespot[5691]: time="2026-10-12T05:39:08+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:39:08 bcik go-librespot[5691]: time="2026-10-12T05:39:08+02:00" level=debug msg="app state loaded" Oct 12 05:39:08 bcik go-librespot[5691]: time="2026-10-12T05:39:08+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:39:08 bcik go-librespot[5691]: time="2026-10-12T05:39:08+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 05:39:08 bcik go-librespot[5691]: time="2026-10-12T05:39:08+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 05:39:08 bcik go-librespot[5691]: time="2026-10-12T05:39:08+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 05:39:08 bcik go-librespot[5691]: time="2026-10-12T05:39:08+02:00" level=info msg="zeroconf server listening on port 40401" Oct 12 05:39:08 bcik go-librespot[5691]: time="2026-10-12T05:39:08+02:00" level=debug msg="obtained new client token: AAGcEmfRFhvDdbLkvp7xZv/l8sim+rfyWUnIMdtEs3xaM7+HWje1ib5jwhmo9PTKINK4lVypHmgp2t0ng4iDwsvD/mUhIaxQGxKjCOtuVuHxoxP+JHPE/1o66U2hCdTtnFgAxN2oBU6k5QeLkOK99/YnmYtcdmDh+yt0GwrOE7Li/RSVsG6IU6B+RS3IQwlgRhLyT5nK3X/rspLxl9syNE1XujO5XSBB+81gv0pxKz07F19OZGvb" Oct 12 05:39:08 bcik go-librespot[5691]: time="2026-10-12T05:39:08+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:39:08 bcik go-librespot[5691]: time="2026-10-12T05:39:08+02:00" level=debug msg="completed keyexchange" Oct 12 05:39:08 bcik go-librespot[5691]: time="2026-10-12T05:39:08+02:00" level=debug msg="completed challenge" Oct 12 05:39:08 bcik go-librespot[5691]: time="2026-10-12T05:39:08+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:39:08 bcik go-librespot[5691]: time="2026-10-12T05:39:08+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:39:08 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:39:08 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:39:08 bcik volumio[5340]: info: Initializing connection to go-librespot Websocket Oct 12 05:39:08 bcik volumio[5340]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:39:11 bcik systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4597. Oct 12 05:39:11 bcik systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:39:11 bcik systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 12 05:39:11 bcik go-librespot[5714]: go-librespot daemon starting... Oct 12 05:39:11 bcik go-librespot[5715]: time="2026-10-12T05:39:11+02:00" level=info msg="running go-librespot 0.6.2" Oct 12 05:39:11 bcik go-librespot[5715]: time="2026-10-12T05:39:11+02:00" level=debug msg="app state loaded" Oct 12 05:39:11 bcik go-librespot[5715]: time="2026-10-12T05:39:11+02:00" level=info msg="api server listening on 127.0.0.1:9879" Oct 12 05:39:11 bcik go-librespot[5715]: time="2026-10-12T05:39:11+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 12 05:39:11 bcik go-librespot[5715]: time="2026-10-12T05:39:11+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 12 05:39:11 bcik go-librespot[5715]: time="2026-10-12T05:39:11+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 12 05:39:11 bcik go-librespot[5715]: time="2026-10-12T05:39:11+02:00" level=info msg="zeroconf server listening on port 37395" Oct 12 05:39:11 bcik volumio[5340]: info: Initializing connection to go-librespot Websocket Oct 12 05:39:11 bcik go-librespot[5715]: time="2026-10-12T05:39:11+02:00" level=debug msg="new websocket client" Oct 12 05:39:11 bcik volumio[5340]: info: Connection to go-librespot Websocket established Oct 12 05:39:11 bcik go-librespot[5715]: time="2026-10-12T05:39:11+02:00" level=debug msg="obtained new client token: AAEdLMZFYAkB5kuaSmRFIqkPerGQ7MbL64foBcuh6pEGkE/xfQLOzLRKfwp9TLQWPoEEX8R/RfKSXpHG+bYzxmr78LL67jPhdY5BCkubwwVxn7GLeWaHscAfld9Y02AJScSbfN8rwaEBWwuipIuHuxpJbo7liAUSgoaCq1zxRyGpE2dpZjeH2j5ENQN+QHILtjiJLiUlt5fj5t2Zr7pHp7nmiex+TMFsDYWW9q1UVZjhefr0AN8HVEA=" Oct 12 05:39:11 bcik go-librespot[5715]: time="2026-10-12T05:39:11+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 05:39:11 bcik go-librespot[5715]: time="2026-10-12T05:39:11+02:00" level=debug msg="completed keyexchange" Oct 12 05:39:11 bcik go-librespot[5715]: time="2026-10-12T05:39:11+02:00" level=debug msg="completed challenge" Oct 12 05:39:11 bcik go-librespot[5715]: time="2026-10-12T05:39:11+02:00" level=info msg="authenticated AP" username="la***pl" Oct 12 05:39:11 bcik go-librespot[5715]: time="2026-10-12T05:39:11+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Oct 12 05:39:11 bcik systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 12 05:39:11 bcik systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 12 05:39:11 bcik volumio[5340]: info: Connection to go-librespot Websocket closed Oct 12 05:39:14 bcik volumio[5340]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 12 05:39:14 bcik volumio[5340]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Oct 12 05:39:14 bcik volumio[5340]: info: CoreCommandRouter::volumioGetState Oct 12 05:39:14 bcik volumio[5340]: info: CorePlayQueue::getTrack 0 Oct 12 05:39:14 bcik volumio[5340]: info: Getting Spotify volume Oct 12 05:39:14 bcik volumio[5340]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 05:39:14 bcik volumio[5340]: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 12 05:39:14 bcik volumio[5340]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Oct 12 05:39:14 bcik volumio[5340]: errno: -111, Oct 12 05:39:14 bcik volumio[5340]: code: 'ECONNREFUSED', Oct 12 05:39:14 bcik volumio[5340]: syscall: 'connect', Oct 12 05:39:14 bcik volumio[5340]: address: '127.0.0.1', Oct 12 05:39:14 bcik volumio[5340]: port: 9879, Oct 12 05:39:14 bcik volumio[5340]: response: undefined Oct 12 05:39:14 bcik volumio[5340]: } Oct 12 05:39:14 bcik volumio[5340]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 05:39:14 bcik sudo[5738]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-12 05:38' Oct 12 05:39:14 bcik sudo[5738]: 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"