Feb 13 02:25:00 volumio volumio[11577]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Feb 13 02:25:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13.
Feb 13 02:25:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:25:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:25:00 volumio go-librespot[12001]: go-librespot daemon starting...
Feb 13 02:25:00 volumio go-librespot[12002]: time="2026-02-13T02:25:00+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 02:25:00 volumio go-librespot[12002]: time="2026-02-13T02:25:00+07:00" level=debug msg="app state loaded"
Feb 13 02:25:00 volumio go-librespot[12002]: time="2026-02-13T02:25:00+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 02:25:01 volumio go-librespot[12002]: time="2026-02-13T02:25:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 13 02:25:01 volumio go-librespot[12002]: time="2026-02-13T02:25:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Feb 13 02:25:01 volumio go-librespot[12002]: time="2026-02-13T02:25:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Feb 13 02:25:01 volumio go-librespot[12002]: time="2026-02-13T02:25:01+07:00" level=info msg="zeroconf server listening on port 33211"
Feb 13 02:25:01 volumio go-librespot[12002]: time="2026-02-13T02:25:01+07:00" level=debug msg="obtained new client token: AACkMQO50QH4D8cWMF/rvuDRYCw3lp15uydyVXlgXG5Xe+cHaVy1E0cebTO7MwI6qYolgwxdvo25wLVwXK5i5vgT8cgv2SOV3Z5U0jgi/qro2ytuyoRKLesJ8hRkmsq+FhSpvfmywpb5RhKRpM8diwVXLYLDvT7RxvBq9v5WFtXMMQs7aYsv1Wn+ilMMsphpki3onXge4bPKSSXs2iUlChrMCqaMLCKlXzPS3atyWS79pTIyblf3pD+5zw=="
Feb 13 02:25:01 volumio go-librespot[12002]: time="2026-02-13T02:25:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 02:25:01 volumio go-librespot[12002]: time="2026-02-13T02:25:01+07:00" level=debug msg="completed keyexchange"
Feb 13 02:25:01 volumio go-librespot[12002]: time="2026-02-13T02:25:01+07:00" level=debug msg="completed challenge"
Feb 13 02:25:01 volumio go-librespot[12002]: time="2026-02-13T02:25:01+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 02:25:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 02:25:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 02:25:02 volumio volumio[11577]: info: Initializing connection to go-librespot Websocket
Feb 13 02:25:02 volumio volumio[11577]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 02:25:03 volumio volumio[11577]: info: MYVOLUMIO: Adding device
Feb 13 02:25:03 volumio volumio[11577]: info: MYVOLUMIO: Evaluating Server
Feb 13 02:25:04 volumio volumio[11577]: info: Setting Geolocation for MyVolumio to as1
Feb 13 02:25:04 volumio volumio[11577]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 02:25:04 volumio volumio[11577]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 02:25:04 volumio volumio[11577]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 02:25:04 volumio volumio[11577]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Feb 13 02:25:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14.
Feb 13 02:25:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:25:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:25:05 volumio go-librespot[12042]: go-librespot daemon starting...
Feb 13 02:25:05 volumio go-librespot[12043]: time="2026-02-13T02:25:05+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 02:25:05 volumio go-librespot[12043]: time="2026-02-13T02:25:05+07:00" level=debug msg="app state loaded"
Feb 13 02:25:05 volumio go-librespot[12043]: time="2026-02-13T02:25:05+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 02:25:05 volumio volumio[11577]: info: Updating MyVolumio device info
Feb 13 02:25:05 volumio volumio[11577]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 02:25:05 volumio volumio[11577]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 02:25:05 volumio volumio[11577]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 02:25:05 volumio volumio[11577]: info: Initializing connection to go-librespot Websocket
Feb 13 02:25:05 volumio go-librespot[12043]: time="2026-02-13T02:25:05+07:00" level=debug msg="new websocket client"
Feb 13 02:25:05 volumio volumio[11577]: info: Connection to go-librespot Websocket established
Feb 13 02:25:05 volumio go-librespot[12043]: time="2026-02-13T02:25:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 13 02:25:05 volumio go-librespot[12043]: time="2026-02-13T02:25:05+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Feb 13 02:25:05 volumio go-librespot[12043]: time="2026-02-13T02:25:05+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Feb 13 02:25:05 volumio go-librespot[12043]: time="2026-02-13T02:25:05+07:00" level=info msg="zeroconf server listening on port 38359"
Feb 13 02:25:05 volumio volumio[11577]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Feb 13 02:25:05 volumio go-librespot[12043]: time="2026-02-13T02:25:05+07:00" level=debug msg="obtained new client token: AABmMNLzvI2eJ0U+i7LM10iOqmauJUOdkx06J9RPBaEHeRNSIg4WWYTnXElvRlYk8I6wSMjcEE8rj4H+TOzxdPc/ZWXsERb8DuG8fiGD4WH9DwupRES3dcYdHtntYna36xPAY+clPpEzxSLuS0gTAqBPq4u8Jv9B+eGG31kYZt18J8Tv/ySguNi49jzMlnVzmzvAN1TCz5QD0v2fv4O62C8DXmanDO9vW1wFBaD47SkEWt5tnvQ2Rm1hZQ=="
Feb 13 02:25:05 volumio go-librespot[12043]: time="2026-02-13T02:25:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 02:25:06 volumio go-librespot[12043]: time="2026-02-13T02:25:06+07:00" level=debug msg="completed keyexchange"
Feb 13 02:25:06 volumio go-librespot[12043]: time="2026-02-13T02:25:06+07:00" level=debug msg="completed challenge"
Feb 13 02:25:06 volumio go-librespot[12043]: time="2026-02-13T02:25:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 02:25:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 02:25:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 02:25:06 volumio volumio[11577]: info: Connection to go-librespot Websocket closed
Feb 13 02:25:07 volumio volumio[11577]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 13 02:25:07 volumio volumio[11577]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 02:25:07 volumio volumio[11577]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Feb 13 02:25:07 volumio volumio-remote-updater[643]: Test mode disabled
Feb 13 02:25:07 volumio volumio-remote-updater[643]: Alpha mode disabled
Feb 13 02:25:07 volumio volumio-remote-updater[643]: Alpha legacy test mode disabled
Feb 13 02:25:07 volumio volumio[11577]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Feb 13 02:25:08 volumio volumio[11577]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
\n\n- Fix for CPU utilization spike
\n- Fix for triggerhappy input permission
\n
\nNEW ADDITIONS
\n\n- Add BLE onboarding plugin
\n- Enable vc4-kms-v3d for all compatible RPi models
\n- Update Tidal SDK
\n
\n","title":"Update v4.096","updateavailable":true}
Feb 13 02:25:08 volumio volumio[11577]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Feb 13 02:25:08 volumio volumio[11577]: info: Getting Spotify volume
Feb 13 02:25:08 volumio volumio[11577]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 13 02:25:08 volumio volumio[11577]: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 02:25:08 volumio volumio[11577]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Feb 13 02:25:08 volumio volumio[11577]: errno: -111,
Feb 13 02:25:08 volumio volumio[11577]: code: 'ECONNREFUSED',
Feb 13 02:25:08 volumio volumio[11577]: syscall: 'connect',
Feb 13 02:25:08 volumio volumio[11577]: address: '127.0.0.1',
Feb 13 02:25:08 volumio volumio[11577]: port: 9879,
Feb 13 02:25:08 volumio volumio[11577]: response: undefined
Feb 13 02:25:08 volumio volumio[11577]: }
Feb 13 02:25:08 volumio volumio[11577]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 13 02:25:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15.
Feb 13 02:25:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:25:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:25:09 volumio go-librespot[12067]: go-librespot daemon starting...
Feb 13 02:25:09 volumio go-librespot[12068]: time="2026-02-13T02:25:09+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 02:25:09 volumio go-librespot[12068]: time="2026-02-13T02:25:09+07:00" level=debug msg="app state loaded"
Feb 13 02:25:09 volumio go-librespot[12068]: time="2026-02-13T02:25:09+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 02:25:09 volumio go-librespot[12068]: time="2026-02-13T02:25:09+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 13 02:25:09 volumio go-librespot[12068]: time="2026-02-13T02:25:09+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Feb 13 02:25:09 volumio go-librespot[12068]: time="2026-02-13T02:25:09+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Feb 13 02:25:09 volumio go-librespot[12068]: time="2026-02-13T02:25:09+07:00" level=info msg="zeroconf server listening on port 33783"
Feb 13 02:25:10 volumio sudo[12077]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-13 02:24'
Feb 13 02:25:10 volumio sudo[12077]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:25:10 volumio go-librespot[12068]: time="2026-02-13T02:25:10+07:00" level=debug msg="obtained new client token: AAComDvWQYOfT9drUjWAiu1uJ9ZkV3GkRKUZTJVoOE7bXQ3Ekxa20VSA65cWC+FfShu2pLkUx/jASFgj8Joemt5AJ64A8qbrcF6sMlnUJit1wXKzY15b2ESrzkckx7e0MfVsvogzXQAXgpzhDPADi9d1ey46HqarCJ8hdHDwo1Vkw5JOT+4R/QBbgLuQZLNEowP2vGwo4rQ5F7iwHvz8A0bJCt0/ev4HL7PqGIpVghSbIKUrG+xV3tk="
Feb 13 02:25:10 volumio go-librespot[12068]: time="2026-02-13T02:25:10+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused"
Feb 13 02:25:10 volumio sudo[12077]: pam_unix(sudo:session): session closed for user root
Feb 13 02:25:10 volumio go-librespot[12068]: time="2026-02-13T02:25:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 13 02:25:10 volumio go-librespot[12068]: time="2026-02-13T02:25:10+07:00" level=debug msg="completed keyexchange"
Feb 13 02:25:10 volumio go-librespot[12068]: time="2026-02-13T02:25:10+07:00" level=debug msg="completed challenge"
Feb 13 02:25:10 volumio volumio-remote-updater[643]: [2026-02-13 02:25:10] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Feb 13 02:25:10 volumio volumio-remote-updater[643]: [2026-02-13 02:25:10] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Feb 13 02:25:10 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 02:25:10 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Feb 13 02:25:10 volumio systemd[1]: volumio.service: Consumed 58.455s CPU time.
Feb 13 02:25:10 volumio go-librespot[12068]: time="2026-02-13T02:25:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 02:25:10 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 13 02:25:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 02:25:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 02:25:10 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 13 02:25:10 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 14120.
Feb 13 02:25:10 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 13 02:25:10 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Feb 13 02:25:10 volumio systemd[1]: volumio.service: Consumed 58.455s CPU time.
Feb 13 02:25:10 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Feb 13 02:25:10 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 13 02:25:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16.
Feb 13 02:25:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:25:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:25:13 volumio go-librespot[12108]: go-librespot daemon starting...
Feb 13 02:25:13 volumio go-librespot[12109]: time="2026-02-13T02:25:13+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 02:25:13 volumio go-librespot[12109]: time="2026-02-13T02:25:13+07:00" level=debug msg="app state loaded"
Feb 13 02:25:13 volumio go-librespot[12109]: time="2026-02-13T02:25:13+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 02:25:14 volumio volumio[12092]: info: -------------------------------------------
Feb 13 02:25:14 volumio volumio[12092]: info: ----- Volumio3 ----
Feb 13 02:25:14 volumio volumio[12092]: info: -------------------------------------------
Feb 13 02:25:14 volumio volumio[12092]: info: ----- System startup ----
Feb 13 02:25:14 volumio volumio[12092]: info: -------------------------------------------
Feb 13 02:25:14 volumio go-librespot[12109]: time="2026-02-13T02:25:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 13 02:25:14 volumio go-librespot[12109]: time="2026-02-13T02:25:14+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Feb 13 02:25:14 volumio go-librespot[12109]: time="2026-02-13T02:25:14+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Feb 13 02:25:14 volumio go-librespot[12109]: time="2026-02-13T02:25:14+07:00" level=info msg="zeroconf server listening on port 46637"
Feb 13 02:25:14 volumio go-librespot[12109]: time="2026-02-13T02:25:14+07:00" level=debug msg="obtained new client token: AACmiTptWyvmZ1LoNPHqyRyaajTEOqaW37cxCDHkHMPmZgqvd9Cxt4XEJhHKmologXgIEkxQb4TrT2L2Rzk2ICdgguLHI/41K/rZoJRmOih+7UpILQDOjz6NmK3DnGnXk3Ilms8n5NuzSPXwyYOU+0RTowqQNQ/4YeX8LlVx9PmOWlt4ddwQ+9RqwUhIKs98rC3WhcS6ILEg/HxHYVw1nQf6pIITowScOFSjAwKUpRLcD/NjL7xwl/7+9Q=="
Feb 13 02:25:14 volumio go-librespot[12109]: time="2026-02-13T02:25:14+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused"
Feb 13 02:25:14 volumio go-librespot[12109]: time="2026-02-13T02:25:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 13 02:25:14 volumio go-librespot[12109]: time="2026-02-13T02:25:14+07:00" level=debug msg="completed keyexchange"
Feb 13 02:25:14 volumio go-librespot[12109]: time="2026-02-13T02:25:14+07:00" level=debug msg="completed challenge"
Feb 13 02:25:14 volumio go-librespot[12109]: time="2026-02-13T02:25:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 02:25:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 02:25:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 02:25:15 volumio volumio-remote-updater[643]: [2026-02-13 02:25:15] [connect] Successful connection
Feb 13 02:25:15 volumio volumio[12092]: info: MYVOLUMIO Environment detected
Feb 13 02:25:15 volumio volumio[12092]: info: Plugin folders cleanup
Feb 13 02:25:15 volumio volumio[12092]: info: Scanning into folder /volumio/app/plugins/
Feb 13 02:25:15 volumio volumio[12092]: info: Scanning category audio_interface
Feb 13 02:25:15 volumio volumio[12092]: info: Scanning category miscellanea
Feb 13 02:25:15 volumio volumio[12092]: info: Scanning category music_service
Feb 13 02:25:15 volumio volumio[12092]: info: Scanning category plugins.json
Feb 13 02:25:15 volumio volumio[12092]: info: Scanning category system_controller
Feb 13 02:25:15 volumio volumio[12092]: info: Scanning category user_interface
Feb 13 02:25:15 volumio volumio[12092]: info: Scanning into folder /data/plugins/
Feb 13 02:25:15 volumio volumio[12092]: info: Scanning category music_service
Feb 13 02:25:15 volumio volumio[12092]: info: Plugin folders cleanup completed
Feb 13 02:25:15 volumio volumio[12092]: info: -------------------------------------------
Feb 13 02:25:15 volumio volumio[12092]: info: ----- Core plugins startup ----
Feb 13 02:25:15 volumio volumio[12092]: info: -------------------------------------------
Feb 13 02:25:15 volumio volumio[12092]: info: Loading plugins from folder /volumio/app/plugins/
Feb 13 02:25:15 volumio volumio[12092]: info: Adding plugin upnp to MyMusic Plugins
Feb 13 02:25:15 volumio volumio[12092]: info: Adding plugin airplay_emulation to MyMusic Plugins
Feb 13 02:25:15 volumio volumio[12092]: info: Adding plugin upnp_browser to MyMusic Plugins
Feb 13 02:25:15 volumio volumio[12092]: info: Loading plugins from folder /data/plugins/
Feb 13 02:25:15 volumio volumio[12092]: info: Loading plugin "system"...
Feb 13 02:25:15 volumio volumio[12092]: info: Loading plugin "appearance"...
Feb 13 02:25:17 volumio volumio[12092]: info: Loading plugin "network"...
Feb 13 02:25:17 volumio volumio[12092]: info: Refreshing Cached IP Addresses
Feb 13 02:25:17 volumio sudo[12129]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 13 02:25:17 volumio sudo[12129]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:25:17 volumio sudo[12131]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 13 02:25:17 volumio sudo[12131]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:25:17 volumio sudo[12129]: pam_unix(sudo:session): session closed for user root
Feb 13 02:25:17 volumio volumio[12092]: info: Loading plugin "services"...
Feb 13 02:25:17 volumio sudo[12131]: pam_unix(sudo:session): session closed for user root
Feb 13 02:25:17 volumio volumio[12092]: info: Loading plugin "alsa_controller"...
Feb 13 02:25:17 volumio sudo[12140]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Feb 13 02:25:17 volumio sudo[12140]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:25:18 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 13 02:25:18 volumio volumio[12092]: info: Loading plugin "wizard"...
Feb 13 02:25:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17.
Feb 13 02:25:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:25:18 volumio volumio[12092]: info: Loading plugin "networkfs"...
Feb 13 02:25:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:25:18 volumio volumio[12092]: info: Starting Udev Watcher for removable devices
Feb 13 02:25:18 volumio go-librespot[12162]: go-librespot daemon starting...
Feb 13 02:25:18 volumio go-librespot[12163]: time="2026-02-13T02:25:18+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 02:25:18 volumio go-librespot[12163]: time="2026-02-13T02:25:18+07:00" level=debug msg="app state loaded"
Feb 13 02:25:18 volumio go-librespot[12163]: time="2026-02-13T02:25:18+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 02:25:18 volumio volumio[12092]: info: Ignoring mount for partition: boot
Feb 13 02:25:18 volumio volumio[12092]: info: Ignoring mount for partition: volumio
Feb 13 02:25:18 volumio volumio[12092]: info: Ignoring mount for partition: volumio_data
Feb 13 02:25:18 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 13 02:25:18 volumio volumio[12092]: info: Loading plugin "volumio_command_line_client"...
Feb 13 02:25:18 volumio volumio[12092]: info: Loading plugin "upnp"...
Feb 13 02:25:18 volumio volumio[12092]: info: [1770924318224] Starting Upmpd Daemon
Feb 13 02:25:18 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 13 02:25:18 volumio volumio[12092]: info: Loading plugin "my_music"...
Feb 13 02:25:18 volumio volumio[12092]: info: Loading plugin "mpd"...
Feb 13 02:25:18 volumio go-librespot[12163]: time="2026-02-13T02:25:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 13 02:25:18 volumio go-librespot[12163]: time="2026-02-13T02:25:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 13 02:25:18 volumio go-librespot[12163]: time="2026-02-13T02:25:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 13 02:25:18 volumio go-librespot[12163]: time="2026-02-13T02:25:18+07:00" level=info msg="zeroconf server listening on port 37191"
Feb 13 02:25:18 volumio volumio[12092]: info: Loading plugin "upnp_browser"...
Feb 13 02:25:19 volumio go-librespot[12163]: time="2026-02-13T02:25:19+07:00" level=debug msg="obtained new client token: AAAApWPWXVWWOXQGCy6zGWT9qP1WjMv6UQ1HS/RaOBg1QndS4qq0bYbI5NcIesmJXq4h+GGHBPiD5Sma/u3Yi7WAWTG9BZOyvNpP0UYCvEGu+4sH814Hd4fl8T6M6asq54GH6JHt8XachYLyZH2HOr3LuR1wTHrwYVk3hEV8YrdHa+dH+6nEuBIe0cBTF12bI0MHZPoTlBomUpqbHDoK/2Sm/fGERURW7ZW+btu7+/SkCO4rXEackHPJqA=="
Feb 13 02:25:19 volumio go-librespot[12163]: time="2026-02-13T02:25:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 02:25:19 volumio go-librespot[12163]: time="2026-02-13T02:25:19+07:00" level=debug msg="completed keyexchange"
Feb 13 02:25:19 volumio go-librespot[12163]: time="2026-02-13T02:25:19+07:00" level=debug msg="completed challenge"
Feb 13 02:25:19 volumio go-librespot[12163]: time="2026-02-13T02:25:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 02:25:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 02:25:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 02:25:20 volumio sudo[12140]: pam_unix(sudo:session): session closed for user root
Feb 13 02:25:21 volumio volumio[12092]: info: Starting UPNP Browser
Feb 13 02:25:21 volumio volumio[12092]: info: Loading plugin "alarm-clock"...
Feb 13 02:25:22 volumio volumio[12092]: info: Loading plugin "airplay_emulation"...
Feb 13 02:25:22 volumio volumio[12092]: info: Starting Shairport Sync
Feb 13 02:25:22 volumio volumio[12092]: info: Loading plugin "last_100"...
Feb 13 02:25:22 volumio volumio[12092]: info: Loading plugin "webradio"...
Feb 13 02:25:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18.
Feb 13 02:25:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:25:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:25:22 volumio go-librespot[12172]: go-librespot daemon starting...
Feb 13 02:25:22 volumio volumio[12092]: info: Loading plugin "i2s_dacs"...
Feb 13 02:25:22 volumio go-librespot[12173]: time="2026-02-13T02:25:22+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 02:25:22 volumio go-librespot[12173]: time="2026-02-13T02:25:22+07:00" level=debug msg="app state loaded"
Feb 13 02:25:22 volumio go-librespot[12173]: time="2026-02-13T02:25:22+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 02:25:22 volumio volumio[12092]: info: Loading plugin "volumiodiscovery"...
Feb 13 02:25:22 volumio volumio[12092]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 13 02:25:22 volumio volumio[12092]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 13 02:25:22 volumio volumio[12092]: *** WARNING *** For more information see
Feb 13 02:25:22 volumio volumio[12092]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 13 02:25:22 volumio volumio[12092]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 13 02:25:22 volumio volumio[12092]: *** WARNING *** For more information see
Feb 13 02:25:22 volumio node[12092]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 13 02:25:22 volumio node[12092]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 13 02:25:22 volumio node[12092]: *** WARNING *** For more information see
Feb 13 02:25:22 volumio node[12092]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 13 02:25:22 volumio node[12092]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 13 02:25:22 volumio node[12092]: *** WARNING *** For more information see
Feb 13 02:25:22 volumio volumio[12092]: info: Applying required configuration parameters for plugin volumiodiscovery
Feb 13 02:25:22 volumio volumio[12092]: info: Discovery: Started advertising with name: Volumio
Feb 13 02:25:22 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 13 02:25:22 volumio volumio[12092]: info: Loading plugin "spop"...
Feb 13 02:25:22 volumio go-librespot[12173]: time="2026-02-13T02:25:22+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 13 02:25:22 volumio go-librespot[12173]: time="2026-02-13T02:25:22+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 13 02:25:22 volumio go-librespot[12173]: time="2026-02-13T02:25:22+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 13 02:25:22 volumio go-librespot[12173]: time="2026-02-13T02:25:22+07:00" level=info msg="zeroconf server listening on port 39589"
Feb 13 02:25:23 volumio go-librespot[12173]: time="2026-02-13T02:25:23+07:00" level=debug msg="obtained new client token: AACL9EmcRH4+gKNbYKm0NF/QbZD064tbvf7isbyMdc9jdZE/FIewDycdOgn+YRaBgxbCbAxnfX+LSupD6DIUeMjHPV48veiJDF3slz2EQkf+DZCIr3bUEZYCueT9zOPDnJ/AjQIHaVWkYSZ5+QyLIdTs9oz6BIi9NZBy6wRtkAwBsMMuAzzKZjeZprI/yXootCz6QIdTObfK/GRuIlGBCG4gnd9CMd43uAXwL7JG0QEsFNrbjJ52K68="
Feb 13 02:25:23 volumio go-librespot[12173]: time="2026-02-13T02:25:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 02:25:23 volumio go-librespot[12173]: time="2026-02-13T02:25:23+07:00" level=debug msg="completed keyexchange"
Feb 13 02:25:23 volumio go-librespot[12173]: time="2026-02-13T02:25:23+07:00" level=debug msg="completed challenge"
Feb 13 02:25:23 volumio go-librespot[12173]: time="2026-02-13T02:25:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 02:25:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 02:25:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 02:25:24 volumio volumio[12092]: info: Loading plugin "ytcr"...
Feb 13 02:25:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19.
Feb 13 02:25:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:25:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:25:26 volumio go-librespot[12184]: go-librespot daemon starting...
Feb 13 02:25:26 volumio go-librespot[12185]: time="2026-02-13T02:25:26+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 02:25:26 volumio go-librespot[12185]: time="2026-02-13T02:25:26+07:00" level=debug msg="app state loaded"
Feb 13 02:25:26 volumio go-librespot[12185]: time="2026-02-13T02:25:26+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 02:25:27 volumio volumio[12092]: info: Loading plugin "ytmusic"...
Feb 13 02:25:27 volumio go-librespot[12185]: time="2026-02-13T02:25:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 13 02:25:27 volumio go-librespot[12185]: time="2026-02-13T02:25:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Feb 13 02:25:27 volumio go-librespot[12185]: time="2026-02-13T02:25:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Feb 13 02:25:27 volumio go-librespot[12185]: time="2026-02-13T02:25:27+07:00" level=info msg="zeroconf server listening on port 39307"
Feb 13 02:25:27 volumio go-librespot[12185]: time="2026-02-13T02:25:27+07:00" level=debug msg="obtained new client token: AADO85Fo1BSIMbB73da4VPxbFPlTmhCPYacn5Ne2cODUnDra/+mIZ4uhIK2YWhGl66aQzo+0qJ38yHQS7a4+LJYPeJW9y53m3FrRMkJYRv2kxXqzsJabm6Qz4oWHmY/tzwq6wJVoN/lsqwlZcdZzcUzMS6f0+7QatZqxvGVQaU4k0QDpQTZjarmkY+U5YfRAJgSZ/dik8TNsYy/Kzi18cS+tNbwhqo+0t8w2RNq/1vVILjM65KfZLKrGng=="
Feb 13 02:25:27 volumio go-librespot[12185]: time="2026-02-13T02:25:27+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused"
Feb 13 02:25:27 volumio go-librespot[12185]: time="2026-02-13T02:25:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 13 02:25:27 volumio go-librespot[12185]: time="2026-02-13T02:25:27+07:00" level=debug msg="completed keyexchange"
Feb 13 02:25:27 volumio go-librespot[12185]: time="2026-02-13T02:25:27+07:00" level=debug msg="completed challenge"
Feb 13 02:25:27 volumio go-librespot[12185]: time="2026-02-13T02:25:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 02:25:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 02:25:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 02:25:27 volumio volumio-remote-updater[643]: [2026-02-13 02:25:27] [connect] Successful connection
Feb 13 02:25:28 volumio volumio[12092]: info: Loading plugin "outputs"...
Feb 13 02:25:28 volumio volumio[12092]: info: Loading plugin "albumart"...
Feb 13 02:25:28 volumio volumio[12092]: info: Plugin example_plugin is not enabled
Feb 13 02:25:28 volumio volumio[12092]: info: Loading plugin "inputs"...
Feb 13 02:25:28 volumio volumio[12092]: info: Loading plugin "updater_comm"...
Feb 13 02:25:28 volumio volumio[12092]: info: Plugin mpdemulation is not enabled
Feb 13 02:25:28 volumio volumio[12092]: info: Loading plugin "rest_api"...
Feb 13 02:25:28 volumio volumio[12092]: info: Loading plugin "websocket"...
Feb 13 02:25:28 volumio volumio[12092]: info: Starting Socket.io Server version 1.7.4
Feb 13 02:25:28 volumio volumio[12092]: info: Loading plugin "RoonBridge"...
Feb 13 02:25:29 volumio volumio[12092]: info: Applying required configuration parameters for plugin RoonBridge
Feb 13 02:25:29 volumio volumio[12092]: info: Loading i18n strings for locale en
Feb 13 02:25:29 volumio volumio[12092]: Updating browse sources language
Feb 13 02:25:29 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 13 02:25:29 volumio volumio[12207]: Forking 3 albumart workers
Feb 13 02:25:29 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 13 02:25:29 volumio volumio[12092]: info: CoreCommandRouter::initPlayerControls
Feb 13 02:25:29 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:29 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:29 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:29 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:29 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:29 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:29 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:29 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:29 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 13 02:25:29 volumio volumio[12092]: Express server listening on port 3000
Feb 13 02:25:29 volumio volumio[12092]: [Metrics] WebUI: 16s 118.40ms
Feb 13 02:25:29 volumio volumio[12092]: info: CoreStateMachine::resetVolumioState
Feb 13 02:25:29 volumio volumio[12092]: info: CoreStateMachine::getcurrentVolume
Feb 13 02:25:29 volumio volumio[12092]: info: CoreCommandRouter::volumioRetrievevolume
Feb 13 02:25:29 volumio sudo[12252]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 13 02:25:29 volumio sudo[12252]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:25:29 volumio sudo[12252]: pam_unix(sudo:session): session closed for user root
Feb 13 02:25:29 volumio volumio[12092]: info: Volumio Network Manager: Network status updated: 1
Feb 13 02:25:29 volumio sudo[12254]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 13 02:25:29 volumio sudo[12254]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:25:29 volumio sudo[12254]: pam_unix(sudo:session): session closed for user root
Feb 13 02:25:29 volumio volumio[12092]: info: VolumeController:: Volume=100 Mute =false
Feb 13 02:25:29 volumio volumio[12092]: info: CoreStateMachine::pushState
Feb 13 02:25:30 volumio volumio[12092]: info: CorePlayQueue::getTrack 0
Feb 13 02:25:30 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 13 02:25:30 volumio volumio[12092]: info: CoreCommandRouter::volumioPushState
Feb 13 02:25:30 volumio volumio[12092]: info: CoreStateMachine::updateTrackBlock
Feb 13 02:25:30 volumio volumio[12092]: info: CorePlayQueue::getTrackBlock
Feb 13 02:25:30 volumio volumio[12092]: info: CoreCommandRouter::volumioRetrievevolume
Feb 13 02:25:30 volumio volumio-remote-updater[643]: [2026-02-13 02:25:30] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770924327 101
Feb 13 02:25:30 volumio volumio[12092]: 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: 1
Feb 13 02:25:30 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 02:25:30 volumio volumio[12092]: info: Reloading queue from file
Feb 13 02:25:30 volumio volumio[12092]: info: CoreStateMachine::setRepeat null single undefined
Feb 13 02:25:30 volumio volumio[12092]: info: CoreStateMachine::pushState
Feb 13 02:25:30 volumio volumio[12092]: info: CorePlayQueue::getTrack 0
Feb 13 02:25:30 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 13 02:25:30 volumio volumio[12092]: info: CoreCommandRouter::volumioPushState
Feb 13 02:25:30 volumio volumio[12092]: info: CoreStateMachine::setRandom null
Feb 13 02:25:30 volumio volumio[12092]: info: CoreStateMachine::pushState
Feb 13 02:25:30 volumio volumio[12092]: info: CorePlayQueue::getTrack 0
Feb 13 02:25:30 volumio volumio[12092]: info: CoreCommandRouter::volumioPushState
Feb 13 02:25:30 volumio volumio[12092]: info: Setting Device type: Raspberry PI
Feb 13 02:25:30 volumio volumio[12092]: info: Completed loading Core Plugins
Feb 13 02:25:30 volumio volumio[12092]: info: Preparing to generate the ALSA configuration file
Feb 13 02:25:30 volumio volumio[12092]: info: VolumeController:: Volume=100 Mute =false
Feb 13 02:25:30 volumio volumio[12092]: info: CoreStateMachine::pushState
Feb 13 02:25:30 volumio volumio[12092]: info: CorePlayQueue::getTrack 0
Feb 13 02:25:30 volumio volumio[12092]: info: CoreCommandRouter::volumioPushState
Feb 13 02:25:30 volumio volumio[12092]: info: Asound.conf file unchanged, so no further update is needed
Feb 13 02:25:30 volumio volumio[12092]: info: Output device has changed, restarting MPD
Feb 13 02:25:30 volumio volumio[12092]: info: Output device has changed, restarting Shairport Sync
Feb 13 02:25:30 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:30 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 02:25:30 volumio sudo[12267]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Feb 13 02:25:30 volumio sudo[12267]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:25:30 volumio sudo[12269]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 13 02:25:30 volumio sudo[12269]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:25:30 volumio sudo[12269]: pam_unix(sudo:session): session closed for user root
Feb 13 02:25:30 volumio volumio[12092]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 13 02:25:30 volumio sudo[12271]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 13 02:25:30 volumio sudo[12271]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:25:30 volumio volumio[12092]: info: ___________ START PLUGINS ___________
Feb 13 02:25:30 volumio volumio[12092]: info: ControllerMpd::onStart: Initializing MPD
Feb 13 02:25:30 volumio volumio[12092]: info: Creating MPD Configuration file
Feb 13 02:25:30 volumio sudo[12267]: pam_unix(sudo:session): session closed for user root
Feb 13 02:25:30 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Feb 13 02:25:30 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 13 02:25:30 volumio volumio[12092]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 13 02:25:30 volumio volumio[12092]: info: [1770924330921] CoreMusicLibrary::Adding element Media Servers
Feb 13 02:25:30 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 13 02:25:30 volumio sudo[12280]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 13 02:25:30 volumio sudo[12280]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:25:30 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 13 02:25:30 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 13 02:25:30 volumio systemd[1]: mpd.service: Consumed 7.037s CPU time.
Feb 13 02:25:31 volumio volumio[12092]: info: UPNP Browser: Client initialized successfully
Feb 13 02:25:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20.
Feb 13 02:25:31 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 13 02:25:31 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 13 02:25:31 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 13 02:25:31 volumio sudo[12282]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 13 02:25:31 volumio sudo[12282]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:25:31 volumio sudo[12280]: pam_unix(sudo:session): session closed for user root
Feb 13 02:25:31 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:31 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 02:25:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 13 02:25:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:25:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:25:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 13 02:25:31 volumio go-librespot[12290]: go-librespot daemon starting...
Feb 13 02:25:31 volumio volumio[12092]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 13 02:25:31 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:31 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 02:25:31 volumio volumio[12092]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 13 02:25:31 volumio volumio[12092]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 13 02:25:31 volumio volumio[12092]: info: [1770924331220] CoreMusicLibrary::Adding element Last_100
Feb 13 02:25:31 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 13 02:25:31 volumio go-librespot[12292]: time="2026-02-13T02:25:31+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 02:25:31 volumio go-librespot[12292]: time="2026-02-13T02:25:31+07:00" level=debug msg="app state loaded"
Feb 13 02:25:31 volumio go-librespot[12292]: time="2026-02-13T02:25:31+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 02:25:31 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 13 02:25:31 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 13 02:25:31 volumio volumio[12092]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 13 02:25:31 volumio volumio[12092]: info: [1770924331259] CoreMusicLibrary::Adding element Webradio
Feb 13 02:25:31 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 13 02:25:31 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 13 02:25:31 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 13 02:25:31 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 13 02:25:31 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 13 02:25:31 volumio volumio[12092]: info: Initializing BBC Radios
Feb 13 02:25:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 13 02:25:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 13 02:25:31 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 13 02:25:31 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 02:25:31 volumio volumio[12092]: info: Creating Spotify config file
Feb 13 02:25:31 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:31 volumio sudo[12311]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 13 02:25:31 volumio sudo[12311]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 13 02:25:31 volumio sudo[12311]: pam_unix(sudo:session): session closed for user root
Feb 13 02:25:31 volumio go-librespot[12292]: time="2026-02-13T02:25:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 13 02:25:31 volumio go-librespot[12292]: time="2026-02-13T02:25:31+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 13 02:25:31 volumio go-librespot[12292]: time="2026-02-13T02:25:31+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 13 02:25:31 volumio go-librespot[12292]: time="2026-02-13T02:25:31+07:00" level=info msg="zeroconf server listening on port 43105"
Feb 13 02:25:32 volumio go-librespot[12292]: time="2026-02-13T02:25:32+07:00" level=debug msg="obtained new client token: AACu06wL22hsj/NP32eD5AELqd6fCMX2+UtWchb+ce8M5n6n6bkihR4/ckscLmnkSiMD9MlWWzXxXadXf5J1PG9ZpUOu7f9LA4cfRDqgOVT/m9T396KVGmPwgg8RvZJV5/w71gaNmH5EOoYa2Kuj17W7SvJ8VNFYRn2w9B5Lyn3hI+oa9MFGGwaZjLdtGtIGxvWTpdxpQRVvCdp02PuOQw3wFahMmucsqworxFCdlyVDyYOyz0ZOTkg="
Feb 13 02:25:32 volumio go-librespot[12292]: time="2026-02-13T02:25:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 02:25:32 volumio go-librespot[12292]: time="2026-02-13T02:25:32+07:00" level=debug msg="completed keyexchange"
Feb 13 02:25:32 volumio go-librespot[12292]: time="2026-02-13T02:25:32+07:00" level=debug msg="completed challenge"
Feb 13 02:25:32 volumio go-librespot[12292]: time="2026-02-13T02:25:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 02:25:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 02:25:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 02:25:32 volumio volumio[12219]: Starting albumart workers
Feb 13 02:25:32 volumio volumio[12217]: Starting albumart workers
Feb 13 02:25:32 volumio volumio[12218]: Starting albumart workers
Feb 13 02:25:32 volumio volumio[12092]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 13 02:25:32 volumio volumio[12092]: info: [1770924332912] CoreMusicLibrary::Adding element YouTube Music
Feb 13 02:25:32 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 13 02:25:32 volumio volumio[12092]: Cannot find translation for source YouTube Music
Feb 13 02:25:32 volumio volumio[12092]: info: Volumio Calling Home
Feb 13 02:25:33 volumio sudo[12324]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service
Feb 13 02:25:33 volumio sudo[12324]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:25:33 volumio sudo[12324]: pam_unix(sudo:session): session closed for user root
Feb 13 02:25:33 volumio volumio[12092]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7
Feb 13 02:25:33 volumio volumio[12092]: info: Discovery: Found device Volumio
Feb 13 02:25:33 volumio volumio[12092]: info: CoreCommandRouter::volumioGetState
Feb 13 02:25:33 volumio volumio[12092]: info: CorePlayQueue::getTrack 0
Feb 13 02:25:33 volumio volumio[12092]: info: MPD Permissions set
Feb 13 02:25:33 volumio volumio[12092]: info: MPD Permissions set
Feb 13 02:25:33 volumio volumio[12092]: info: Upmpdcli Daemon Started
Feb 13 02:25:33 volumio volumio[12092]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7
Feb 13 02:25:33 volumio volumio[12092]: info: Discovery: Found device Volumio
Feb 13 02:25:33 volumio volumio[12092]: info: CoreCommandRouter::volumioGetState
Feb 13 02:25:33 volumio volumio[12092]: info: CorePlayQueue::getTrack 0
Feb 13 02:25:33 volumio volumio[12092]: info: Volumio called home
Feb 13 02:25:34 volumio volumio[12092]: info: Spotify config file written
Feb 13 02:25:34 volumio sudo[12330]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 13 02:25:34 volumio sudo[12330]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:25:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:25:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:25:34 volumio go-librespot[12332]: go-librespot daemon starting...
Feb 13 02:25:34 volumio sudo[12330]: pam_unix(sudo:session): session closed for user root
Feb 13 02:25:34 volumio go-librespot[12333]: time="2026-02-13T02:25:34+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 02:25:34 volumio go-librespot[12333]: time="2026-02-13T02:25:34+07:00" level=debug msg="app state loaded"
Feb 13 02:25:34 volumio go-librespot[12333]: time="2026-02-13T02:25:34+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 02:25:34 volumio volumio[12092]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2
Feb 13 02:25:34 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:34 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:34 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:34 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:34 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:34 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:34 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:34 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:34 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 02:25:34 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:34 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:34 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:34 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:34 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:34 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:34 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:34 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:34 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:34 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 02:25:34 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:25:34 volumio volumio[12092]: info: No need to fix Spotify hosts
Feb 13 02:25:35 volumio go-librespot[12333]: time="2026-02-13T02:25:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 13 02:25:35 volumio go-librespot[12333]: time="2026-02-13T02:25:35+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 13 02:25:35 volumio go-librespot[12333]: time="2026-02-13T02:25:35+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 13 02:25:35 volumio go-librespot[12333]: time="2026-02-13T02:25:35+07:00" level=info msg="zeroconf server listening on port 41159"
Feb 13 02:25:35 volumio go-librespot[12333]: time="2026-02-13T02:25:35+07:00" level=debug msg="obtained new client token: AADA0mFLhYyNjMZ9H31B3PIHe/RVr+IBke7ct9M/Du263KxJCaUmaDN1Ur/Sr1yxHCbZyn4VUgdQ7Tbg8bI/fTP0bJQ1KYcHIhExaNTlBfybukoyaEVvNe2G0p5VdKFarQtJR0V50j9smsO6E3KNJ21e1kDyFYtv4Y8ufIL2ewxLGQSE28fHv51tVZ+haiCYI7JRalq2T2xWaxyhzQCkmcKwkZurqPos4agi+p/rGrkMQl9RFno8Eo4="
Feb 13 02:25:35 volumio go-librespot[12333]: time="2026-02-13T02:25:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 02:25:35 volumio go-librespot[12333]: time="2026-02-13T02:25:35+07:00" level=debug msg="completed keyexchange"
Feb 13 02:25:35 volumio go-librespot[12333]: time="2026-02-13T02:25:35+07:00" level=debug msg="completed challenge"
Feb 13 02:25:35 volumio volumio[12092]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 13 02:25:35 volumio volumio[12092]: SPOTIFY: BQCzhYbX4J70KWJ4IFvoCveW6Y8DyiKZcpoPRcZE2TYh_ynwkllzZu0hu0u6nNCvlM4c3RgLlDwSRAnzuanQ_GaMWus-Lp5U-NqoeB8CQGryXj-qAWo1BtjTjinEf8LXkpO3c3qyKldTmnqgZ-TLl5kQcjnRbCRA14tnVoYH9HLH03_uWvl6t6lDE4LJWcuLWbgfisJKS05dQm0QA--Jp6XMUP_U_v1I_2UtIFstWB224709xNVZqpWmTUnXyVRBykL4qOzSh9r6m3ATlcVUJ-9JZJqiVwiGg9KuRf8GasHKPJ8yuu5slZ0c
Feb 13 02:25:35 volumio volumio[12092]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 13 02:25:35 volumio volumio[12092]: info: New Spotify access token = BQCzhYbX4J70KWJ4IFvoCveW6Y8DyiKZcpoPRcZE2TYh_ynwkllzZu0hu0u6nNCvlM4c3RgLlDwSRAnzuanQ_GaMWus-Lp5U-NqoeB8CQGryXj-qAWo1BtjTjinEf8LXkpO3c3qyKldTmnqgZ-TLl5kQcjnRbCRA14tnVoYH9HLH03_uWvl6t6lDE4LJWcuLWbgfisJKS05dQm0QA--Jp6XMUP_U_v1I_2UtIFstWB224709xNVZqpWmTUnXyVRBykL4qOzSh9r6m3ATlcVUJ-9JZJqiVwiGg9KuRf8GasHKPJ8yuu5slZ0c
Feb 13 02:25:35 volumio volumio[12092]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 13 02:25:35 volumio go-librespot[12333]: time="2026-02-13T02:25:35+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 02:25:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 02:25:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 02:25:35 volumio volumio[12092]: info: Starting Shairport Sync
Feb 13 02:25:35 volumio volumio[12092]: info: Starting Shairport Sync
Feb 13 02:25:35 volumio volumio[12092]: info: Starting Shairport Sync
Feb 13 02:25:35 volumio sudo[12369]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 13 02:25:35 volumio sudo[12369]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:25:35 volumio sudo[12371]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 13 02:25:35 volumio sudo[12371]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:25:35 volumio sudo[12373]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 13 02:25:35 volumio sudo[12373]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:25:35 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 13 02:25:35 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 13 02:25:35 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 13 02:25:35 volumio systemd[1]: shairport-sync.service: Consumed 2.459s CPU time.
Feb 13 02:25:35 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 13 02:25:35 volumio volumio[12092]: info: CoreCommandRouter::volumioGetState
Feb 13 02:25:35 volumio volumio[12092]: info: CorePlayQueue::getTrack 0
Feb 13 02:25:35 volumio sudo[12369]: pam_unix(sudo:session): session closed for user root
Feb 13 02:25:36 volumio volumio[12092]: info: Shairport-Sync Started
Feb 13 02:25:36 volumio volumio[12092]: Error adding Membership: Error: addMembership EINVAL
Feb 13 02:25:36 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 13 02:25:36 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 13 02:25:36 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 13 02:25:36 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 13 02:25:36 volumio sudo[12371]: pam_unix(sudo:session): session closed for user root
Feb 13 02:25:36 volumio sudo[12373]: pam_unix(sudo:session): session closed for user root
Feb 13 02:25:36 volumio volumio[12092]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"}
Feb 13 02:25:36 volumio volumio[12092]: info: Spotify Successfully logged in
Feb 13 02:25:36 volumio volumio[12092]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 13 02:25:36 volumio volumio[12092]: info: [1770924336354] CoreMusicLibrary::Adding element Spotify
Feb 13 02:25:36 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 13 02:25:36 volumio volumio[12092]: Cannot find translation for source YouTube Music
Feb 13 02:25:36 volumio volumio[12092]: Cannot find translation for source Spotify
Feb 13 02:25:36 volumio volumio[12092]: info: Shairport-Sync Started
Feb 13 02:25:36 volumio volumio[12092]: info: Shairport-Sync Started
Feb 13 02:25:36 volumio volumio[12092]: info: [yt-cast-receiver] DIAL server listening on port 8098
Feb 13 02:25:36 volumio volumio[12092]: info: CoreCommandRouter::volumioRetrievevolume
Feb 13 02:25:37 volumio volumio[12092]: info: VolumeController:: Volume=100 Mute =false
Feb 13 02:25:37 volumio volumio[12092]: info: CoreCommandRouter::volumioGetState
Feb 13 02:25:37 volumio volumio[12092]: info: CorePlayQueue::getTrack 0
Feb 13 02:25:37 volumio volumio[12092]: info: CoreStateMachine::pushState
Feb 13 02:25:37 volumio volumio[12092]: info: CorePlayQueue::getTrack 0
Feb 13 02:25:37 volumio volumio[12092]: info: CoreCommandRouter::volumioPushState
Feb 13 02:25:38 volumio volumio[12092]: info: go-librespot daemon successfully initialized
Feb 13 02:25:38 volumio mpd[12320]: 2026-02-13T02:25:38 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 13 02:25:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21.
Feb 13 02:25:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:25:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:25:38 volumio go-librespot[12414]: go-librespot daemon starting...
Feb 13 02:25:38 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Feb 13 02:25:38 volumio sudo[12282]: pam_unix(sudo:session): session closed for user root
Feb 13 02:25:38 volumio sudo[12271]: pam_unix(sudo:session): session closed for user root
Feb 13 02:25:38 volumio go-librespot[12415]: time="2026-02-13T02:25:38+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 02:25:38 volumio go-librespot[12415]: time="2026-02-13T02:25:38+07:00" level=debug msg="app state loaded"
Feb 13 02:25:38 volumio go-librespot[12415]: time="2026-02-13T02:25:38+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 02:25:39 volumio volumio[12092]: info: Completed starting Core Plugins
Feb 13 02:25:39 volumio volumio[12092]: info: -------------------------------------------
Feb 13 02:25:39 volumio volumio[12092]: info: ----- MyVolumio plugins startup ----
Feb 13 02:25:39 volumio volumio[12092]: info: -------------------------------------------
Feb 13 02:25:39 volumio volumio[12092]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 13 02:25:39 volumio volumio[12092]: error: MPD error: The expression evaluated to a falsy value:
Feb 13 02:25:39 volumio volumio[12092]: assert.ok(self.idling)
Feb 13 02:25:39 volumio volumio[12092]: error: The expression evaluated to a falsy value:
Feb 13 02:25:39 volumio volumio[12092]: assert.ok(self.idling)
Feb 13 02:25:39 volumio volumio[12092]: error: updateQueue error: null
Feb 13 02:25:39 volumio volumio[12092]: info: MPD running with PID12320
Feb 13 02:25:39 volumio volumio[12092]: ,establishing connection
Feb 13 02:25:39 volumio volumio[12092]: error: updateQueue error: null
Feb 13 02:25:39 volumio go-librespot[12415]: time="2026-02-13T02:25:39+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 13 02:25:39 volumio go-librespot[12415]: time="2026-02-13T02:25:39+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 13 02:25:39 volumio go-librespot[12415]: time="2026-02-13T02:25:39+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 13 02:25:39 volumio go-librespot[12415]: time="2026-02-13T02:25:39+07:00" level=info msg="zeroconf server listening on port 44819"
Feb 13 02:25:39 volumio go-librespot[12415]: time="2026-02-13T02:25:39+07:00" level=debug msg="obtained new client token: AAAO8EFbfAxJ7KfRxU2OSnUT7YVPjlRxhV66NAo/jxP5bYmU+yUHpvZBA8qai/1IcXQU4G2R53KDXUzNe8DpqATiPd+RO/fp/997QwHFuvNiWizG2GHMGga+CG1M0gctktkmJgkoEpcbvL3lHSPw5F8jGRbvn4CmkDCOgidA0jit7+hjUQVhyETcxQTunPL3K6wbzR/WwlIcsKF5lvliDozlZZ9SuG6RrBUNkgHflF1O/eJvuExTNmhtpA=="
Feb 13 02:25:39 volumio go-librespot[12415]: time="2026-02-13T02:25:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 02:25:39 volumio go-librespot[12415]: time="2026-02-13T02:25:39+07:00" level=debug msg="completed keyexchange"
Feb 13 02:25:39 volumio go-librespot[12415]: time="2026-02-13T02:25:39+07:00" level=debug msg="completed challenge"
Feb 13 02:25:39 volumio go-librespot[12415]: time="2026-02-13T02:25:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 02:25:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 02:25:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 02:25:41 volumio volumio[12092]: info: Initializing connection to go-librespot Websocket
Feb 13 02:25:41 volumio volumio[12092]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 02:25:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22.
Feb 13 02:25:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:25:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:25:43 volumio go-librespot[12426]: go-librespot daemon starting...
Feb 13 02:25:43 volumio go-librespot[12427]: time="2026-02-13T02:25:43+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 02:25:43 volumio go-librespot[12427]: time="2026-02-13T02:25:43+07:00" level=debug msg="app state loaded"
Feb 13 02:25:43 volumio go-librespot[12427]: time="2026-02-13T02:25:43+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 02:25:43 volumio go-librespot[12427]: time="2026-02-13T02:25:43+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 13 02:25:43 volumio go-librespot[12427]: time="2026-02-13T02:25:43+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 13 02:25:43 volumio go-librespot[12427]: time="2026-02-13T02:25:43+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 13 02:25:43 volumio go-librespot[12427]: time="2026-02-13T02:25:43+07:00" level=info msg="zeroconf server listening on port 42841"
Feb 13 02:25:43 volumio go-librespot[12427]: time="2026-02-13T02:25:43+07:00" level=debug msg="obtained new client token: AACNXwaOZSaSp8RzynTZ5OMqbBaGVcJvrdiHgoIWP0VIGMQhaLAZJnLh5XlBLc9iS0r/Gkpl0cJIhrdILYY/z5o1a4WxIpsg8GW7aNFUJzJeHM2tMa1diQ1K3UC3y2JlG99BcneHPiV8TeVnu8MFpOicjy/ddzO5mh+6t2mNeEXh0IGR440522cFYAOGF6EWe1KRLQYP68Q13XOa0fFltHXhJ3EdLpDoY6VjoWd4ZPFOGbmjBC+D3PFq+A=="
Feb 13 02:25:44 volumio go-librespot[12427]: time="2026-02-13T02:25:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 02:25:44 volumio volumio[12092]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory
Feb 13 02:25:44 volumio go-librespot[12427]: time="2026-02-13T02:25:44+07:00" level=debug msg="completed keyexchange"
Feb 13 02:25:44 volumio go-librespot[12427]: time="2026-02-13T02:25:44+07:00" level=debug msg="completed challenge"
Feb 13 02:25:44 volumio go-librespot[12427]: time="2026-02-13T02:25:44+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 02:25:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 02:25:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 02:25:44 volumio volumio[12092]: info: Initializing connection to go-librespot Websocket
Feb 13 02:25:44 volumio volumio[12092]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 02:25:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23.
Feb 13 02:25:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:25:47 volumio volumio[12092]: info: Initializing connection to go-librespot Websocket
Feb 13 02:25:47 volumio volumio[12092]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 02:25:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:25:47 volumio go-librespot[12435]: go-librespot daemon starting...
Feb 13 02:25:47 volumio go-librespot[12436]: time="2026-02-13T02:25:47+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 02:25:47 volumio go-librespot[12436]: time="2026-02-13T02:25:47+07:00" level=debug msg="app state loaded"
Feb 13 02:25:47 volumio go-librespot[12436]: time="2026-02-13T02:25:47+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 02:25:47 volumio go-librespot[12436]: time="2026-02-13T02:25:47+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 13 02:25:47 volumio go-librespot[12436]: time="2026-02-13T02:25:47+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 13 02:25:47 volumio go-librespot[12436]: time="2026-02-13T02:25:47+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 13 02:25:47 volumio go-librespot[12436]: time="2026-02-13T02:25:47+07:00" level=info msg="zeroconf server listening on port 44021"
Feb 13 02:25:47 volumio volumio[12092]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Feb 13 02:25:47 volumio volumio[12092]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Feb 13 02:25:47 volumio volumio[12092]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Feb 13 02:25:47 volumio volumio[12092]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Feb 13 02:25:47 volumio volumio[12092]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Feb 13 02:25:47 volumio volumio[12092]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Feb 13 02:25:47 volumio volumio[12092]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Feb 13 02:25:47 volumio volumio[12092]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Feb 13 02:25:47 volumio volumio[12092]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Feb 13 02:25:47 volumio volumio[12092]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Feb 13 02:25:47 volumio volumio[12092]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Feb 13 02:25:47 volumio volumio[12092]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Feb 13 02:25:47 volumio volumio[12092]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Feb 13 02:25:47 volumio volumio[12092]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Feb 13 02:25:47 volumio volumio[12092]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Feb 13 02:25:47 volumio volumio[12092]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Feb 13 02:25:47 volumio volumio[12092]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Feb 13 02:25:47 volumio volumio[12092]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Feb 13 02:25:47 volumio volumio[12092]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Feb 13 02:25:47 volumio volumio[12092]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Feb 13 02:25:47 volumio volumio[12092]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Feb 13 02:25:47 volumio volumio[12092]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Feb 13 02:25:47 volumio volumio[12092]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Feb 13 02:25:47 volumio volumio[12092]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Feb 13 02:25:47 volumio volumio[12092]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Feb 13 02:25:47 volumio volumio[12092]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Feb 13 02:25:47 volumio volumio[12092]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Feb 13 02:25:47 volumio volumio[12092]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Feb 13 02:25:47 volumio volumio[12092]: info: Adding plugin bluetooth to MyMusic Plugins
Feb 13 02:25:47 volumio volumio[12092]: info: Adding plugin multiroom to MyMusic Plugins
Feb 13 02:25:47 volumio volumio[12092]: info: Adding plugin metavolumio to MyMusic Plugins
Feb 13 02:25:47 volumio volumio[12092]: info: Adding plugin cd_controller to MyMusic Plugins
Feb 13 02:25:47 volumio volumio[12092]: info: Adding plugin qobuzconnect to MyMusic Plugins
Feb 13 02:25:47 volumio volumio[12092]: info: Adding plugin smart_inputs to MyMusic Plugins
Feb 13 02:25:48 volumio volumio[12092]: info: Adding plugin tidalconnect to MyMusic Plugins
Feb 13 02:25:48 volumio volumio[12092]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Feb 13 02:25:48 volumio go-librespot[12436]: time="2026-02-13T02:25:48+07:00" level=debug msg="obtained new client token: AACtIOpps31P+GuWK+1RYZ+OcmcTxFiiIybZUIZN0//UPnDnS+UKIUeMmvLiGZnpqVMPXEDIm6Q9aSYnpuAKh6W6dKD2s8bD6NjFech2VO8sRzYqCGPfA65+cs/6WtaSPg4MJWPGUB1MsS7j+Tao8+BaUNbOGv8fKq+mLXKx2p6Vv4ErsfUIDyoRt9Wb5yCQqUMtuZKHJCJeMgxg3XAibEXslvEpTsL0yqAX6GN4Sy91kOkHJI5OTBw="
Feb 13 02:25:48 volumio go-librespot[12436]: time="2026-02-13T02:25:48+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused"
Feb 13 02:25:48 volumio go-librespot[12436]: time="2026-02-13T02:25:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 13 02:25:48 volumio go-librespot[12436]: time="2026-02-13T02:25:48+07:00" level=debug msg="completed keyexchange"
Feb 13 02:25:48 volumio go-librespot[12436]: time="2026-02-13T02:25:48+07:00" level=debug msg="completed challenge"
Feb 13 02:25:48 volumio go-librespot[12436]: time="2026-02-13T02:25:48+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 02:25:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 02:25:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 02:25:49 volumio volumio[12092]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Feb 13 02:25:49 volumio volumio[12092]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Feb 13 02:25:49 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 02:25:49 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 02:25:49 volumio volumio[12092]: info: Starting MyVolumio Remote Streaming Endpoints
Feb 13 02:25:49 volumio volumio[12092]: info: MyVolumio login type: Token
Feb 13 02:25:49 volumio volumio[12092]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Feb 13 02:25:49 volumio volumio[12092]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Feb 13 02:25:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24.
Feb 13 02:25:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:25:51 volumio volumio[12092]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Feb 13 02:25:51 volumio volumio[12092]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Feb 13 02:25:51 volumio volumio[12092]: info: Streaming services startup
Feb 13 02:25:51 volumio volumio[12092]: info: Starting Streaming Daemon
Feb 13 02:25:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:25:51 volumio go-librespot[12457]: go-librespot daemon starting...
Feb 13 02:25:51 volumio go-librespot[12460]: time="2026-02-13T02:25:51+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 02:25:51 volumio go-librespot[12460]: time="2026-02-13T02:25:51+07:00" level=debug msg="app state loaded"
Feb 13 02:25:51 volumio go-librespot[12460]: time="2026-02-13T02:25:51+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 02:25:51 volumio sudo[12461]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 13 02:25:51 volumio sudo[12461]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:25:51 volumio volumio[12092]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Feb 13 02:25:51 volumio sudo[12461]: pam_unix(sudo:session): session closed for user root
Feb 13 02:25:51 volumio volumio[12092]: info: Initializing connection to go-librespot Websocket
Feb 13 02:25:51 volumio volumio[12092]: error: Cannot start Volumio Streaming Daemon
Feb 13 02:25:51 volumio volumio[12092]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 13 02:25:51 volumio volumio[12092]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 13 02:25:51 volumio go-librespot[12460]: time="2026-02-13T02:25:51+07:00" level=debug msg="new websocket client"
Feb 13 02:25:51 volumio volumio[12092]: info: Connection to go-librespot Websocket established
Feb 13 02:25:52 volumio go-librespot[12460]: time="2026-02-13T02:25:52+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 13 02:25:52 volumio go-librespot[12460]: time="2026-02-13T02:25:52+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 13 02:25:52 volumio go-librespot[12460]: time="2026-02-13T02:25:52+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 13 02:25:52 volumio go-librespot[12460]: time="2026-02-13T02:25:52+07:00" level=info msg="zeroconf server listening on port 45379"
Feb 13 02:25:52 volumio go-librespot[12460]: time="2026-02-13T02:25:52+07:00" level=debug msg="obtained new client token: AABz+H5mMaAN+WHlrjOSq0irUVKSEhCxtJCrnhhPhpKSoH4hMEKOBQzuxW0FG9W62fWfTpXs6qxs3JZFKqrujWvl6H2YI8AAK7xDr9D+i71X2f2HrwIGB2bfAvsN2hd1b7VwBdapq04ifQe9UcHKShnVUSmUeWhURXg/4baRbQUZw38DJl4GIJnffaG95LAbbR+3Jky+d0RlAR2UPjgh+8Eg1YocYSAzf7P+ahIesOdfqJ/gFrpKiFydAQ=="
Feb 13 02:25:52 volumio go-librespot[12460]: time="2026-02-13T02:25:52+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused"
Feb 13 02:25:52 volumio go-librespot[12460]: time="2026-02-13T02:25:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 13 02:25:52 volumio go-librespot[12460]: time="2026-02-13T02:25:52+07:00" level=debug msg="completed keyexchange"
Feb 13 02:25:52 volumio go-librespot[12460]: time="2026-02-13T02:25:52+07:00" level=debug msg="completed challenge"
Feb 13 02:25:52 volumio go-librespot[12460]: time="2026-02-13T02:25:52+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 02:25:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 02:25:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 02:25:52 volumio volumio[12092]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Feb 13 02:25:52 volumio volumio[12092]: info: Connection to go-librespot Websocket closed
Feb 13 02:25:53 volumio volumio[12092]: info: MyVolumio token set successfully
Feb 13 02:25:53 volumio volumio[12092]: info: MYVOLUMIO: Adding device
Feb 13 02:25:53 volumio volumio[12092]: info: MYVOLUMIO: Evaluating Server
Feb 13 02:25:54 volumio volumio[12092]: info: MyVolumio status changed
Feb 13 02:25:54 volumio volumio[12092]: info: Streaming services startup
Feb 13 02:25:54 volumio volumio[12092]: info: Starting Streaming Daemon
Feb 13 02:25:54 volumio volumio[12092]: info: Removing browser output: myVolumio user plan is not superstar
Feb 13 02:25:54 volumio volumio[12092]: info: Removing audio output:
Feb 13 02:25:54 volumio volumio[12092]: info: Stoppping Tunnel 1
Feb 13 02:25:54 volumio sudo[12494]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 13 02:25:54 volumio sudo[12494]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:25:54 volumio sudo[12494]: pam_unix(sudo:session): session closed for user root
Feb 13 02:25:54 volumio sudo[12497]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service
Feb 13 02:25:54 volumio sudo[12497]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:25:54 volumio volumio[12092]: error: Cannot start Volumio Streaming Daemon
Feb 13 02:25:54 volumio volumio[12092]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 13 02:25:54 volumio volumio[12092]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 13 02:25:54 volumio volumio[12092]: info: Setting Geolocation for MyVolumio to as1
Feb 13 02:25:54 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 02:25:54 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 02:25:54 volumio volumio[12092]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 02:25:54 volumio 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.
Feb 13 02:25:54 volumio 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.
Feb 13 02:25:54 volumio 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.
Feb 13 02:25:54 volumio 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.
Feb 13 02:25:54 volumio 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.
Feb 13 02:25:54 volumio 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.
Feb 13 02:25:54 volumio 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.
Feb 13 02:25:54 volumio 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.
Feb 13 02:25:54 volumio sudo[12497]: pam_unix(sudo:session): session closed for user root
Feb 13 02:25:54 volumio volumio[12092]: info: Remote SSH Stopped
Feb 13 02:25:54 volumio volumio[12092]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Feb 13 02:25:54 volumio volumio[12092]: info: Getting Spotify volume
Feb 13 02:25:54 volumio volumio[12092]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 13 02:25:54 volumio volumio[12092]: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 02:25:54 volumio volumio[12092]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Feb 13 02:25:54 volumio volumio[12092]: errno: -111,
Feb 13 02:25:54 volumio volumio[12092]: code: 'ECONNREFUSED',
Feb 13 02:25:54 volumio volumio[12092]: syscall: 'connect',
Feb 13 02:25:54 volumio volumio[12092]: address: '127.0.0.1',
Feb 13 02:25:54 volumio volumio[12092]: port: 9879,
Feb 13 02:25:54 volumio volumio[12092]: response: undefined
Feb 13 02:25:54 volumio volumio[12092]: }
Feb 13 02:25:55 volumio volumio[12092]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 13 02:25:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25.
Feb 13 02:25:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:25:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:25:55 volumio go-librespot[12511]: go-librespot daemon starting...
Feb 13 02:25:55 volumio go-librespot[12512]: time="2026-02-13T02:25:55+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 02:25:55 volumio go-librespot[12512]: time="2026-02-13T02:25:55+07:00" level=debug msg="app state loaded"
Feb 13 02:25:55 volumio go-librespot[12512]: time="2026-02-13T02:25:55+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 02:25:56 volumio go-librespot[12512]: time="2026-02-13T02:25:56+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 13 02:25:56 volumio go-librespot[12512]: time="2026-02-13T02:25:56+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Feb 13 02:25:56 volumio go-librespot[12512]: time="2026-02-13T02:25:56+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Feb 13 02:25:56 volumio sudo[12521]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-13 02:24'
Feb 13 02:25:56 volumio sudo[12521]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:25:56 volumio go-librespot[12512]: time="2026-02-13T02:25:56+07:00" level=info msg="zeroconf server listening on port 37919"
Feb 13 02:25:56 volumio go-librespot[12512]: time="2026-02-13T02:25:56+07:00" level=debug msg="obtained new client token: AAB5B5ud12/ox5x8p1q50FoV999WXyKW1M9ddVKbLjBNQ8L6OemF22kYVTpZLu3AWTpty1AOstpBYtcHaEroMIiuI8NZz4oCGAecJtRXKuiBIFSund2jVpv95gmL0cMhFzgxzhoQUYpE7hGuCZufuDyuRFYRcLD5Kzx1FH9t5ko1QSEmYJZVyuM9UWCdLpcKjfJIDNCVpdRqZMwkf49SZmNkcxW78YrBLs2xiUD6WoTSjNBzQPOjnIG1LA=="
Feb 13 02:25:56 volumio go-librespot[12512]: time="2026-02-13T02:25:56+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 02:25:56 volumio go-librespot[12512]: time="2026-02-13T02:25:56+07:00" level=debug msg="completed keyexchange"
Feb 13 02:25:56 volumio go-librespot[12512]: time="2026-02-13T02:25:56+07:00" level=debug msg="completed challenge"
Feb 13 02:25:56 volumio sudo[12521]: pam_unix(sudo:session): session closed for user root
Feb 13 02:25:56 volumio go-librespot[12512]: time="2026-02-13T02:25:56+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 02:25:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 02:25:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 02:25:57 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 02:25:57 volumio volumio-remote-updater[643]: [2026-02-13 02:25:56] [error] handle_read_frame error: asio.system:104 (Connection reset by peer)
Feb 13 02:25:57 volumio volumio-remote-updater[643]: [2026-02-13 02:25:56] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006]
Feb 13 02:25:57 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Feb 13 02:25:57 volumio systemd[1]: volumio.service: Consumed 56.825s CPU time.
Feb 13 02:25:57 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 13 02:25:57 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 13 02:25:57 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 14121.
Feb 13 02:25:57 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 13 02:25:57 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Feb 13 02:25:57 volumio systemd[1]: volumio.service: Consumed 56.825s CPU time.
Feb 13 02:25:57 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Feb 13 02:25:57 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 13 02:26:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26.
Feb 13 02:26:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:26:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:26:00 volumio go-librespot[12549]: go-librespot daemon starting...
Feb 13 02:26:00 volumio go-librespot[12550]: time="2026-02-13T02:26:00+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 02:26:00 volumio go-librespot[12550]: time="2026-02-13T02:26:00+07:00" level=debug msg="app state loaded"
Feb 13 02:26:00 volumio go-librespot[12550]: time="2026-02-13T02:26:00+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 02:26:00 volumio go-librespot[12550]: time="2026-02-13T02:26:00+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 13 02:26:00 volumio go-librespot[12550]: time="2026-02-13T02:26:00+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 13 02:26:00 volumio go-librespot[12550]: time="2026-02-13T02:26:00+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 13 02:26:00 volumio go-librespot[12550]: time="2026-02-13T02:26:00+07:00" level=info msg="zeroconf server listening on port 38069"
Feb 13 02:26:00 volumio volumio[12534]: info: -------------------------------------------
Feb 13 02:26:00 volumio volumio[12534]: info: ----- Volumio3 ----
Feb 13 02:26:00 volumio volumio[12534]: info: -------------------------------------------
Feb 13 02:26:00 volumio volumio[12534]: info: ----- System startup ----
Feb 13 02:26:00 volumio volumio[12534]: info: -------------------------------------------
Feb 13 02:26:00 volumio go-librespot[12550]: time="2026-02-13T02:26:00+07:00" level=debug msg="obtained new client token: AAA61Wfjb1LViHQBs5MHGV00ZCsUUvc6VO7RsPmpFRAL4AUD/lyejtSiqZMNbvueU7CnUVhla5L6NohEcFoLELKF+3BPa3AiFQqLA9+gapz37uAPCZa48uEzpuLJ30DNj37UnPK3pGHpHJyCgjwrNcbK+usF/poRsls5Hdmx81/qnJK7n9kAD/RFtoLQj8VU7DTHPGFV8NkvnZQ62HjP0ri1arPSox8aRRsqQXOY+XTNe/ZfT7BJk4695A=="
Feb 13 02:26:01 volumio go-librespot[12550]: time="2026-02-13T02:26:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 02:26:01 volumio go-librespot[12550]: time="2026-02-13T02:26:01+07:00" level=debug msg="completed keyexchange"
Feb 13 02:26:01 volumio go-librespot[12550]: time="2026-02-13T02:26:01+07:00" level=debug msg="completed challenge"
Feb 13 02:26:01 volumio go-librespot[12550]: time="2026-02-13T02:26:01+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 02:26:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 02:26:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 02:26:02 volumio volumio-remote-updater[643]: [2026-02-13 02:26:01] [connect] Successful connection
Feb 13 02:26:02 volumio volumio[12534]: info: MYVOLUMIO Environment detected
Feb 13 02:26:02 volumio volumio[12534]: info: Plugin folders cleanup
Feb 13 02:26:02 volumio volumio[12534]: info: Scanning into folder /volumio/app/plugins/
Feb 13 02:26:02 volumio volumio[12534]: info: Scanning category audio_interface
Feb 13 02:26:02 volumio volumio[12534]: info: Scanning category miscellanea
Feb 13 02:26:02 volumio volumio[12534]: info: Scanning category music_service
Feb 13 02:26:02 volumio volumio[12534]: info: Scanning category plugins.json
Feb 13 02:26:02 volumio volumio[12534]: info: Scanning category system_controller
Feb 13 02:26:02 volumio volumio[12534]: info: Scanning category user_interface
Feb 13 02:26:02 volumio volumio[12534]: info: Scanning into folder /data/plugins/
Feb 13 02:26:02 volumio volumio[12534]: info: Scanning category music_service
Feb 13 02:26:02 volumio volumio[12534]: info: Plugin folders cleanup completed
Feb 13 02:26:02 volumio volumio[12534]: info: -------------------------------------------
Feb 13 02:26:02 volumio volumio[12534]: info: ----- Core plugins startup ----
Feb 13 02:26:02 volumio volumio[12534]: info: -------------------------------------------
Feb 13 02:26:02 volumio volumio[12534]: info: Loading plugins from folder /volumio/app/plugins/
Feb 13 02:26:02 volumio volumio[12534]: info: Adding plugin upnp to MyMusic Plugins
Feb 13 02:26:02 volumio volumio[12534]: info: Adding plugin airplay_emulation to MyMusic Plugins
Feb 13 02:26:02 volumio volumio[12534]: info: Adding plugin upnp_browser to MyMusic Plugins
Feb 13 02:26:02 volumio volumio[12534]: info: Loading plugins from folder /data/plugins/
Feb 13 02:26:02 volumio volumio[12534]: info: Loading plugin "system"...
Feb 13 02:26:02 volumio volumio[12534]: info: Loading plugin "appearance"...
Feb 13 02:26:04 volumio volumio[12534]: info: Loading plugin "network"...
Feb 13 02:26:04 volumio volumio[12534]: info: Refreshing Cached IP Addresses
Feb 13 02:26:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27.
Feb 13 02:26:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:26:04 volumio sudo[12572]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 13 02:26:04 volumio sudo[12572]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:26:04 volumio sudo[12575]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 13 02:26:04 volumio sudo[12575]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:26:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:26:04 volumio sudo[12572]: pam_unix(sudo:session): session closed for user root
Feb 13 02:26:04 volumio go-librespot[12573]: go-librespot daemon starting...
Feb 13 02:26:04 volumio sudo[12575]: pam_unix(sudo:session): session closed for user root
Feb 13 02:26:04 volumio volumio[12534]: info: Loading plugin "services"...
Feb 13 02:26:04 volumio volumio[12534]: info: Loading plugin "alsa_controller"...
Feb 13 02:26:04 volumio go-librespot[12586]: time="2026-02-13T02:26:04+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 02:26:04 volumio go-librespot[12586]: time="2026-02-13T02:26:04+07:00" level=debug msg="app state loaded"
Feb 13 02:26:04 volumio go-librespot[12586]: time="2026-02-13T02:26:04+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 02:26:04 volumio sudo[12585]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Feb 13 02:26:04 volumio sudo[12585]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:26:04 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 13 02:26:04 volumio volumio[12534]: info: Loading plugin "wizard"...
Feb 13 02:26:04 volumio volumio[12534]: info: Loading plugin "networkfs"...
Feb 13 02:26:04 volumio volumio[12534]: info: Starting Udev Watcher for removable devices
Feb 13 02:26:04 volumio volumio[12534]: info: Ignoring mount for partition: boot
Feb 13 02:26:04 volumio volumio[12534]: info: Ignoring mount for partition: volumio
Feb 13 02:26:04 volumio volumio[12534]: info: Ignoring mount for partition: volumio_data
Feb 13 02:26:04 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 13 02:26:04 volumio volumio[12534]: info: Loading plugin "volumio_command_line_client"...
Feb 13 02:26:04 volumio volumio[12534]: info: Loading plugin "upnp"...
Feb 13 02:26:04 volumio volumio[12534]: info: [1770924364752] Starting Upmpd Daemon
Feb 13 02:26:04 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 13 02:26:04 volumio volumio[12534]: info: Loading plugin "my_music"...
Feb 13 02:26:04 volumio volumio[12534]: info: Loading plugin "mpd"...
Feb 13 02:26:05 volumio go-librespot[12586]: time="2026-02-13T02:26:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 13 02:26:05 volumio go-librespot[12586]: time="2026-02-13T02:26:05+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 13 02:26:05 volumio go-librespot[12586]: time="2026-02-13T02:26:05+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 13 02:26:05 volumio go-librespot[12586]: time="2026-02-13T02:26:05+07:00" level=info msg="zeroconf server listening on port 37043"
Feb 13 02:26:05 volumio go-librespot[12586]: time="2026-02-13T02:26:05+07:00" level=debug msg="obtained new client token: AACQEqUUzDM3bgBN42GNTZplJviKcKs6NpYxnOhRmdWY8ecTJZOKOy4yYC8YqLMdVOobDchrZ4N12W1WVEj/MZAf7QRblN2m8ynML1XrGTm9z7mrghUDd3k3sfl2HDhHBHYKZMChJJq33MOAgYrEdrS8REjTtqiLhVzaODePEpk8/dbJe41PNEUvQg/5+mTBKrxC28b0XgpZIGrmA31uAL4tFHfB+jS0/TKT13rWxARO+QVcnNLq7J0="
Feb 13 02:26:05 volumio go-librespot[12586]: time="2026-02-13T02:26:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 02:26:05 volumio volumio[12534]: info: Loading plugin "upnp_browser"...
Feb 13 02:26:05 volumio go-librespot[12586]: time="2026-02-13T02:26:05+07:00" level=debug msg="completed keyexchange"
Feb 13 02:26:05 volumio go-librespot[12586]: time="2026-02-13T02:26:05+07:00" level=debug msg="completed challenge"
Feb 13 02:26:05 volumio go-librespot[12586]: time="2026-02-13T02:26:05+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 02:26:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 02:26:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 02:26:07 volumio sudo[12585]: pam_unix(sudo:session): session closed for user root
Feb 13 02:26:08 volumio volumio[12534]: info: Starting UPNP Browser
Feb 13 02:26:08 volumio volumio[12534]: info: Loading plugin "alarm-clock"...
Feb 13 02:26:08 volumio volumio[12534]: info: Loading plugin "airplay_emulation"...
Feb 13 02:26:08 volumio volumio[12534]: info: Starting Shairport Sync
Feb 13 02:26:08 volumio volumio[12534]: info: Loading plugin "last_100"...
Feb 13 02:26:08 volumio volumio[12534]: info: Loading plugin "webradio"...
Feb 13 02:26:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28.
Feb 13 02:26:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:26:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:26:08 volumio go-librespot[12615]: go-librespot daemon starting...
Feb 13 02:26:08 volumio go-librespot[12616]: time="2026-02-13T02:26:08+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 02:26:08 volumio go-librespot[12616]: time="2026-02-13T02:26:08+07:00" level=debug msg="app state loaded"
Feb 13 02:26:08 volumio volumio[12534]: info: Loading plugin "i2s_dacs"...
Feb 13 02:26:08 volumio go-librespot[12616]: time="2026-02-13T02:26:08+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 02:26:08 volumio volumio[12534]: info: Loading plugin "volumiodiscovery"...
Feb 13 02:26:09 volumio volumio[12534]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 13 02:26:09 volumio volumio[12534]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 13 02:26:09 volumio volumio[12534]: *** WARNING *** For more information see
Feb 13 02:26:09 volumio volumio[12534]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 13 02:26:09 volumio volumio[12534]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 13 02:26:09 volumio volumio[12534]: *** WARNING *** For more information see
Feb 13 02:26:09 volumio node[12534]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 13 02:26:09 volumio node[12534]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 13 02:26:09 volumio node[12534]: *** WARNING *** For more information see
Feb 13 02:26:09 volumio node[12534]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 13 02:26:09 volumio node[12534]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 13 02:26:09 volumio node[12534]: *** WARNING *** For more information see
Feb 13 02:26:09 volumio volumio[12534]: info: Applying required configuration parameters for plugin volumiodiscovery
Feb 13 02:26:09 volumio volumio[12534]: info: Discovery: Started advertising with name: Volumio
Feb 13 02:26:09 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 13 02:26:09 volumio volumio[12534]: info: Loading plugin "spop"...
Feb 13 02:26:09 volumio go-librespot[12616]: time="2026-02-13T02:26:09+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 13 02:26:09 volumio go-librespot[12616]: time="2026-02-13T02:26:09+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 13 02:26:09 volumio go-librespot[12616]: time="2026-02-13T02:26:09+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 13 02:26:09 volumio go-librespot[12616]: time="2026-02-13T02:26:09+07:00" level=info msg="zeroconf server listening on port 34089"
Feb 13 02:26:09 volumio go-librespot[12616]: time="2026-02-13T02:26:09+07:00" level=debug msg="obtained new client token: AABY6GE+cyBebwxqICvyDTWUNMOurkNOXfTl8+g3mp6l2tnSSasoDzY65cibhueTAPh+mFKPvY4Db0+dNdPF7uvZD7zShn0F2jRnoCnnWYJ+Q/qsdAkVY0ISH4T+yJjVPmC940TZ1npRF6v+hBKtybgez1KfQ3QE4HLJls5i6q4pUJVkYWAlG9N8X6aDv+UHhkLsBtQ7L6V+KdJwAuvp605D45l5C+0oYvLaYA7YWLNoaJ/yGM6CTQ+FWQ=="
Feb 13 02:26:09 volumio go-librespot[12616]: time="2026-02-13T02:26:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 02:26:09 volumio go-librespot[12616]: time="2026-02-13T02:26:09+07:00" level=debug msg="completed keyexchange"
Feb 13 02:26:09 volumio go-librespot[12616]: time="2026-02-13T02:26:09+07:00" level=debug msg="completed challenge"
Feb 13 02:26:09 volumio go-librespot[12616]: time="2026-02-13T02:26:09+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 02:26:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 02:26:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 02:26:11 volumio volumio[12534]: info: Loading plugin "ytcr"...
Feb 13 02:26:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29.
Feb 13 02:26:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:26:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:26:13 volumio go-librespot[12626]: go-librespot daemon starting...
Feb 13 02:26:13 volumio go-librespot[12627]: time="2026-02-13T02:26:13+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 02:26:13 volumio go-librespot[12627]: time="2026-02-13T02:26:13+07:00" level=debug msg="app state loaded"
Feb 13 02:26:13 volumio go-librespot[12627]: time="2026-02-13T02:26:13+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 02:26:13 volumio go-librespot[12627]: time="2026-02-13T02:26:13+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 13 02:26:13 volumio go-librespot[12627]: time="2026-02-13T02:26:13+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 13 02:26:13 volumio go-librespot[12627]: time="2026-02-13T02:26:13+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 13 02:26:13 volumio volumio[12534]: info: Loading plugin "ytmusic"...
Feb 13 02:26:13 volumio go-librespot[12627]: time="2026-02-13T02:26:13+07:00" level=info msg="zeroconf server listening on port 34201"
Feb 13 02:26:13 volumio go-librespot[12627]: time="2026-02-13T02:26:13+07:00" level=debug msg="obtained new client token: AAA9UP6UWcIx6xM8jSZZNpRGq1paciCNbviAgNG/WqOdZufwPyPpj06g0umfOcgsTwOPgMPJea+9lg6dzyDnIzQY9DRijF3n/hfLwCtFeVbRvNU3Xlq/PhZyMYIrhS1PQUdChRhynAvbN9tgjbu7UlGwyA74UqMQwu5CrYOgsmQ93k/jeQlrWka8fpC0IrzCipkfKyxFD1LpUNb7+aoFADxrboMURQZI9s3BGS4I9Gi3REIuU7sMm2HvdA=="
Feb 13 02:26:14 volumio go-librespot[12627]: time="2026-02-13T02:26:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 02:26:14 volumio go-librespot[12627]: time="2026-02-13T02:26:14+07:00" level=debug msg="completed keyexchange"
Feb 13 02:26:14 volumio go-librespot[12627]: time="2026-02-13T02:26:14+07:00" level=debug msg="completed challenge"
Feb 13 02:26:14 volumio go-librespot[12627]: time="2026-02-13T02:26:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 02:26:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 02:26:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 02:26:14 volumio volumio-remote-updater[643]: [2026-02-13 02:26:14] [connect] Successful connection
Feb 13 02:26:14 volumio volumio[12534]: info: Loading plugin "outputs"...
Feb 13 02:26:14 volumio volumio[12534]: info: Loading plugin "albumart"...
Feb 13 02:26:14 volumio volumio[12534]: info: Plugin example_plugin is not enabled
Feb 13 02:26:14 volumio volumio[12534]: info: Loading plugin "inputs"...
Feb 13 02:26:14 volumio volumio[12534]: info: Loading plugin "updater_comm"...
Feb 13 02:26:15 volumio volumio[12534]: info: Plugin mpdemulation is not enabled
Feb 13 02:26:15 volumio volumio[12534]: info: Loading plugin "rest_api"...
Feb 13 02:26:15 volumio volumio[12534]: info: Loading plugin "websocket"...
Feb 13 02:26:15 volumio volumio[12534]: info: Starting Socket.io Server version 1.7.4
Feb 13 02:26:15 volumio volumio[12534]: info: Loading plugin "RoonBridge"...
Feb 13 02:26:15 volumio volumio[12534]: info: Applying required configuration parameters for plugin RoonBridge
Feb 13 02:26:15 volumio volumio[12534]: info: Loading i18n strings for locale en
Feb 13 02:26:15 volumio volumio[12534]: Updating browse sources language
Feb 13 02:26:15 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 13 02:26:15 volumio volumio[12649]: Forking 3 albumart workers
Feb 13 02:26:15 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 13 02:26:15 volumio volumio[12534]: info: CoreCommandRouter::initPlayerControls
Feb 13 02:26:15 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:15 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:15 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:15 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:15 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:15 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:15 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:15 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:15 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 13 02:26:15 volumio volumio[12534]: Express server listening on port 3000
Feb 13 02:26:15 volumio volumio[12534]: [Metrics] WebUI: 16s 173.53ms
Feb 13 02:26:16 volumio volumio[12534]: info: CoreStateMachine::resetVolumioState
Feb 13 02:26:16 volumio volumio[12534]: info: CoreStateMachine::getcurrentVolume
Feb 13 02:26:16 volumio volumio[12534]: info: CoreCommandRouter::volumioRetrievevolume
Feb 13 02:26:16 volumio sudo[12696]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 13 02:26:16 volumio sudo[12693]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 13 02:26:16 volumio sudo[12696]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:26:16 volumio sudo[12693]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:26:16 volumio sudo[12696]: pam_unix(sudo:session): session closed for user root
Feb 13 02:26:16 volumio sudo[12693]: pam_unix(sudo:session): session closed for user root
Feb 13 02:26:16 volumio volumio[12534]: info: Volumio Network Manager: Network status updated: 1
Feb 13 02:26:16 volumio volumio-remote-updater[643]: [2026-02-13 02:26:16] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770924374 101
Feb 13 02:26:16 volumio volumio[12534]: 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: 1
Feb 13 02:26:16 volumio volumio[12534]: info: VolumeController:: Volume=100 Mute =false
Feb 13 02:26:16 volumio volumio[12534]: info: CoreStateMachine::pushState
Feb 13 02:26:16 volumio volumio[12534]: info: CorePlayQueue::getTrack 0
Feb 13 02:26:16 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 13 02:26:16 volumio volumio[12534]: info: CoreCommandRouter::volumioPushState
Feb 13 02:26:16 volumio volumio[12534]: info: CoreStateMachine::updateTrackBlock
Feb 13 02:26:16 volumio volumio[12534]: info: CorePlayQueue::getTrackBlock
Feb 13 02:26:16 volumio volumio[12534]: info: CoreCommandRouter::volumioRetrievevolume
Feb 13 02:26:16 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 02:26:16 volumio volumio[12534]: info: Reloading queue from file
Feb 13 02:26:16 volumio volumio[12534]: info: CoreStateMachine::setRepeat null single undefined
Feb 13 02:26:16 volumio volumio[12534]: info: CoreStateMachine::pushState
Feb 13 02:26:16 volumio volumio[12534]: info: CorePlayQueue::getTrack 0
Feb 13 02:26:16 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 13 02:26:16 volumio volumio[12534]: info: CoreCommandRouter::volumioPushState
Feb 13 02:26:16 volumio volumio[12534]: info: CoreStateMachine::setRandom null
Feb 13 02:26:16 volumio volumio[12534]: info: CoreStateMachine::pushState
Feb 13 02:26:16 volumio volumio[12534]: info: CorePlayQueue::getTrack 0
Feb 13 02:26:16 volumio volumio[12534]: info: CoreCommandRouter::volumioPushState
Feb 13 02:26:16 volumio volumio[12534]: info: Setting Device type: Raspberry PI
Feb 13 02:26:16 volumio volumio[12534]: info: Completed loading Core Plugins
Feb 13 02:26:16 volumio volumio[12534]: info: Preparing to generate the ALSA configuration file
Feb 13 02:26:17 volumio volumio[12534]: info: VolumeController:: Volume=100 Mute =false
Feb 13 02:26:17 volumio volumio[12534]: info: CoreStateMachine::pushState
Feb 13 02:26:17 volumio volumio[12534]: info: CorePlayQueue::getTrack 0
Feb 13 02:26:17 volumio volumio[12534]: info: CoreCommandRouter::volumioPushState
Feb 13 02:26:17 volumio volumio[12534]: info: Asound.conf file unchanged, so no further update is needed
Feb 13 02:26:17 volumio volumio[12534]: info: Output device has changed, restarting MPD
Feb 13 02:26:17 volumio sudo[12709]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Feb 13 02:26:17 volumio sudo[12709]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:26:17 volumio volumio[12534]: info: Output device has changed, restarting Shairport Sync
Feb 13 02:26:17 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:17 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 02:26:17 volumio sudo[12714]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 13 02:26:17 volumio sudo[12714]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:26:17 volumio sudo[12711]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 13 02:26:17 volumio sudo[12711]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:26:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30.
Feb 13 02:26:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:26:17 volumio sudo[12711]: pam_unix(sudo:session): session closed for user root
Feb 13 02:26:17 volumio volumio[12534]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 13 02:26:17 volumio volumio[12534]: info: ___________ START PLUGINS ___________
Feb 13 02:26:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:26:17 volumio go-librespot[12721]: go-librespot daemon starting...
Feb 13 02:26:17 volumio go-librespot[12722]: time="2026-02-13T02:26:17+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 02:26:17 volumio go-librespot[12722]: time="2026-02-13T02:26:17+07:00" level=debug msg="app state loaded"
Feb 13 02:26:17 volumio go-librespot[12722]: time="2026-02-13T02:26:17+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 02:26:17 volumio sudo[12709]: pam_unix(sudo:session): session closed for user root
Feb 13 02:26:17 volumio volumio[12534]: info: ControllerMpd::onStart: Initializing MPD
Feb 13 02:26:17 volumio volumio[12534]: info: Creating MPD Configuration file
Feb 13 02:26:17 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Feb 13 02:26:17 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 13 02:26:17 volumio volumio[12534]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 13 02:26:17 volumio volumio[12534]: info: [1770924377508] CoreMusicLibrary::Adding element Media Servers
Feb 13 02:26:17 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 13 02:26:17 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 13 02:26:17 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 13 02:26:17 volumio systemd[1]: mpd.service: Consumed 7.116s CPU time.
Feb 13 02:26:17 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 13 02:26:17 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 13 02:26:17 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 13 02:26:17 volumio sudo[12729]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 13 02:26:17 volumio sudo[12729]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:26:17 volumio volumio[12534]: info: UPNP Browser: Client initialized successfully
Feb 13 02:26:17 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 13 02:26:17 volumio sudo[12729]: pam_unix(sudo:session): session closed for user root
Feb 13 02:26:17 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 13 02:26:17 volumio sudo[12731]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 13 02:26:17 volumio sudo[12731]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:26:17 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:17 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 02:26:17 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 13 02:26:17 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 13 02:26:17 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 13 02:26:17 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 13 02:26:17 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 13 02:26:17 volumio volumio[12534]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 13 02:26:17 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:17 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 02:26:17 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 13 02:26:17 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 13 02:26:17 volumio volumio[12534]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 13 02:26:17 volumio volumio[12534]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 13 02:26:17 volumio volumio[12534]: info: [1770924377973] CoreMusicLibrary::Adding element Last_100
Feb 13 02:26:17 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 13 02:26:17 volumio volumio[12534]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 13 02:26:17 volumio volumio[12534]: info: [1770924377994] CoreMusicLibrary::Adding element Webradio
Feb 13 02:26:17 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 13 02:26:18 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 13 02:26:18 volumio volumio[12534]: info: Initializing BBC Radios
Feb 13 02:26:18 volumio go-librespot[12722]: time="2026-02-13T02:26:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 13 02:26:18 volumio go-librespot[12722]: time="2026-02-13T02:26:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 13 02:26:18 volumio go-librespot[12722]: time="2026-02-13T02:26:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 13 02:26:18 volumio go-librespot[12722]: time="2026-02-13T02:26:18+07:00" level=info msg="zeroconf server listening on port 33607"
Feb 13 02:26:18 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 13 02:26:18 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 02:26:18 volumio volumio[12534]: info: Creating Spotify config file
Feb 13 02:26:18 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:18 volumio sudo[12746]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 13 02:26:18 volumio sudo[12746]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 13 02:26:18 volumio sudo[12746]: pam_unix(sudo:session): session closed for user root
Feb 13 02:26:18 volumio go-librespot[12722]: time="2026-02-13T02:26:18+07:00" level=debug msg="obtained new client token: AAB1indUDcZgeJtStIw5NHaKuKJY2ovuTXgAfUXd79hzp0D/Jbs5Gip1GuC4CkJUWMgYswIiMcrFjOWKr9lHVnZ6GasDNL6NrLHCWVOapzIKRp9ElqMlT1eo/rCifmhgp76jFaLiNaBEibLDhQkyJbOjkknYjCEqn4vgOCdInCgFX+QWgLPB70OWAR4mtZyTuzbn1NI9fKxGqKdVBID4YLqaURpsFs2iC184ND+pIQNVjKmAaex68ZZu+A=="
Feb 13 02:26:18 volumio go-librespot[12722]: time="2026-02-13T02:26:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 02:26:18 volumio go-librespot[12722]: time="2026-02-13T02:26:18+07:00" level=debug msg="completed keyexchange"
Feb 13 02:26:18 volumio go-librespot[12722]: time="2026-02-13T02:26:18+07:00" level=debug msg="completed challenge"
Feb 13 02:26:18 volumio go-librespot[12722]: time="2026-02-13T02:26:18+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 02:26:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 02:26:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 02:26:19 volumio volumio[12660]: Starting albumart workers
Feb 13 02:26:19 volumio volumio[12661]: Starting albumart workers
Feb 13 02:26:19 volumio volumio[12534]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 13 02:26:19 volumio volumio[12534]: info: [1770924379344] CoreMusicLibrary::Adding element YouTube Music
Feb 13 02:26:19 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 13 02:26:19 volumio volumio[12534]: Cannot find translation for source YouTube Music
Feb 13 02:26:19 volumio volumio[12534]: info: Volumio Calling Home
Feb 13 02:26:19 volumio sudo[12765]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service
Feb 13 02:26:19 volumio sudo[12765]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:26:19 volumio sudo[12765]: pam_unix(sudo:session): session closed for user root
Feb 13 02:26:19 volumio volumio[12534]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7
Feb 13 02:26:19 volumio volumio[12534]: info: Discovery: Found device Volumio
Feb 13 02:26:19 volumio volumio[12534]: info: CoreCommandRouter::volumioGetState
Feb 13 02:26:19 volumio volumio[12534]: info: CorePlayQueue::getTrack 0
Feb 13 02:26:19 volumio volumio[12659]: Starting albumart workers
Feb 13 02:26:20 volumio volumio[12534]: info: MPD Permissions set
Feb 13 02:26:20 volumio volumio[12534]: info: MPD Permissions set
Feb 13 02:26:20 volumio volumio[12534]: info: Upmpdcli Daemon Started
Feb 13 02:26:20 volumio volumio[12534]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7
Feb 13 02:26:20 volumio volumio[12534]: info: Discovery: Found device Volumio
Feb 13 02:26:20 volumio volumio[12534]: info: CoreCommandRouter::volumioGetState
Feb 13 02:26:20 volumio volumio[12534]: info: CorePlayQueue::getTrack 0
Feb 13 02:26:20 volumio volumio[12534]: info: Spotify config file written
Feb 13 02:26:20 volumio sudo[12771]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 13 02:26:20 volumio sudo[12771]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:26:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:26:20 volumio volumio[12534]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2
Feb 13 02:26:20 volumio volumio[12534]: info: Volumio called home
Feb 13 02:26:20 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:20 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:20 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:20 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:20 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:20 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:20 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:26:20 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:20 volumio go-librespot[12773]: go-librespot daemon starting...
Feb 13 02:26:20 volumio sudo[12771]: pam_unix(sudo:session): session closed for user root
Feb 13 02:26:20 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 02:26:20 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:20 volumio go-librespot[12775]: time="2026-02-13T02:26:20+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 02:26:20 volumio go-librespot[12775]: time="2026-02-13T02:26:20+07:00" level=debug msg="app state loaded"
Feb 13 02:26:20 volumio go-librespot[12775]: time="2026-02-13T02:26:20+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 02:26:20 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:20 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:20 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:20 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:20 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:20 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:20 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:20 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:20 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 02:26:20 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 13 02:26:20 volumio volumio[12534]: info: No need to fix Spotify hosts
Feb 13 02:26:21 volumio go-librespot[12775]: time="2026-02-13T02:26:21+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 13 02:26:21 volumio go-librespot[12775]: time="2026-02-13T02:26:21+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 13 02:26:21 volumio go-librespot[12775]: time="2026-02-13T02:26:21+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 13 02:26:21 volumio go-librespot[12775]: time="2026-02-13T02:26:21+07:00" level=info msg="zeroconf server listening on port 33563"
Feb 13 02:26:21 volumio go-librespot[12775]: time="2026-02-13T02:26:21+07:00" level=debug msg="obtained new client token: AADJJltAaVBtS2nphS8d5dGPeWH1CIbfvi10+LzzZ0VCmIYLgY+5kQyqbcipXKFEafNDRSqHL3kvC4dSut/DpmO2N0OXdsYNcnwLsa0GGQddoadLdR5SiC/0rcjzrF7dgHglcaZ+MEIk2keEwBEuMoPZwasPsnGDV4MkwyVG0rQbIBsIucs9yV5PyVDQS6PRTtTiHjK9Y/kWA9i0SpMNSTLoKA4iF+E81tzp2Ygfv8P7etW39L/teoKM7g=="
Feb 13 02:26:21 volumio go-librespot[12775]: time="2026-02-13T02:26:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 02:26:21 volumio go-librespot[12775]: time="2026-02-13T02:26:21+07:00" level=debug msg="completed keyexchange"
Feb 13 02:26:21 volumio go-librespot[12775]: time="2026-02-13T02:26:21+07:00" level=debug msg="completed challenge"
Feb 13 02:26:21 volumio go-librespot[12775]: time="2026-02-13T02:26:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 02:26:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 02:26:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 02:26:22 volumio volumio[12534]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 13 02:26:22 volumio volumio[12534]: SPOTIFY: BQBZHVXkSOL-m4EsEjnVkc0wVp_5li9GAckno7IsflX9ewv534kwP2itOyub4vEMyGOMaXaNsRV2AkirtA-s9v0X7Fm7Ir1XJ_GLNLandWrsFaedv5wsFgG7jht48Ds09coGn1wxGnmxu-DY9QF788Oz2RwfvrcHwxSbppd8v-0TDWoCYoLdT0yaQho8LC0Rq3WYXpUs0HKqDatYZqTqV3V7hjUw3_VFevZzjMiHA52K9TsG0pXD0i4wSqstwNQixM-n2ZwICyCbJA1W7pRIj1R-G4AtiaYQpy-jBRWNp-k9KTkUqpURtinU
Feb 13 02:26:22 volumio volumio[12534]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 13 02:26:22 volumio volumio[12534]: info: New Spotify access token = BQBZHVXkSOL-m4EsEjnVkc0wVp_5li9GAckno7IsflX9ewv534kwP2itOyub4vEMyGOMaXaNsRV2AkirtA-s9v0X7Fm7Ir1XJ_GLNLandWrsFaedv5wsFgG7jht48Ds09coGn1wxGnmxu-DY9QF788Oz2RwfvrcHwxSbppd8v-0TDWoCYoLdT0yaQho8LC0Rq3WYXpUs0HKqDatYZqTqV3V7hjUw3_VFevZzjMiHA52K9TsG0pXD0i4wSqstwNQixM-n2ZwICyCbJA1W7pRIj1R-G4AtiaYQpy-jBRWNp-k9KTkUqpURtinU
Feb 13 02:26:22 volumio volumio[12534]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 13 02:26:22 volumio volumio[12534]: info: Starting Shairport Sync
Feb 13 02:26:22 volumio volumio[12534]: info: Starting Shairport Sync
Feb 13 02:26:22 volumio volumio[12534]: info: Starting Shairport Sync
Feb 13 02:26:22 volumio sudo[12810]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 13 02:26:22 volumio sudo[12810]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:26:22 volumio sudo[12812]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 13 02:26:22 volumio sudo[12812]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:26:22 volumio sudo[12814]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 13 02:26:22 volumio sudo[12814]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:26:22 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 13 02:26:22 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 13 02:26:22 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 13 02:26:22 volumio systemd[1]: shairport-sync.service: Consumed 2.257s CPU time.
Feb 13 02:26:22 volumio volumio[12534]: info: CoreCommandRouter::volumioGetState
Feb 13 02:26:22 volumio volumio[12534]: info: CorePlayQueue::getTrack 0
Feb 13 02:26:22 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 13 02:26:22 volumio sudo[12810]: pam_unix(sudo:session): session closed for user root
Feb 13 02:26:22 volumio sudo[12812]: pam_unix(sudo:session): session closed for user root
Feb 13 02:26:22 volumio sudo[12814]: pam_unix(sudo:session): session closed for user root
Feb 13 02:26:22 volumio volumio[12534]: info: Shairport-Sync Started
Feb 13 02:26:22 volumio volumio[12534]: Error adding Membership: Error: addMembership EINVAL
Feb 13 02:26:22 volumio volumio[12534]: info: Shairport-Sync Started
Feb 13 02:26:22 volumio volumio[12534]: info: Shairport-Sync Started
Feb 13 02:26:22 volumio volumio[12534]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"}
Feb 13 02:26:22 volumio volumio[12534]: info: Spotify Successfully logged in
Feb 13 02:26:22 volumio volumio[12534]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 13 02:26:22 volumio volumio[12534]: info: [1770924382788] CoreMusicLibrary::Adding element Spotify
Feb 13 02:26:22 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 13 02:26:22 volumio volumio[12534]: Cannot find translation for source YouTube Music
Feb 13 02:26:22 volumio volumio[12534]: Cannot find translation for source Spotify
Feb 13 02:26:23 volumio volumio[12534]: info: [yt-cast-receiver] DIAL server listening on port 8098
Feb 13 02:26:23 volumio volumio[12534]: info: CoreCommandRouter::volumioRetrievevolume
Feb 13 02:26:23 volumio volumio[12534]: info: VolumeController:: Volume=100 Mute =false
Feb 13 02:26:23 volumio volumio[12534]: info: CoreCommandRouter::volumioGetState
Feb 13 02:26:23 volumio volumio[12534]: info: CorePlayQueue::getTrack 0
Feb 13 02:26:23 volumio volumio[12534]: info: CoreStateMachine::pushState
Feb 13 02:26:23 volumio volumio[12534]: info: CorePlayQueue::getTrack 0
Feb 13 02:26:23 volumio volumio[12534]: info: CoreCommandRouter::volumioPushState
Feb 13 02:26:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31.
Feb 13 02:26:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:26:25 volumio volumio[12534]: info: go-librespot daemon successfully initialized
Feb 13 02:26:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:26:25 volumio go-librespot[12850]: go-librespot daemon starting...
Feb 13 02:26:25 volumio go-librespot[12851]: time="2026-02-13T02:26:25+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 02:26:25 volumio go-librespot[12851]: time="2026-02-13T02:26:25+07:00" level=debug msg="app state loaded"
Feb 13 02:26:25 volumio go-librespot[12851]: time="2026-02-13T02:26:25+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 02:26:25 volumio mpd[12763]: 2026-02-13T02:26:25 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 13 02:26:25 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Feb 13 02:26:25 volumio sudo[12714]: pam_unix(sudo:session): session closed for user root
Feb 13 02:26:25 volumio sudo[12731]: pam_unix(sudo:session): session closed for user root
Feb 13 02:26:25 volumio go-librespot[12851]: time="2026-02-13T02:26:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 13 02:26:25 volumio go-librespot[12851]: time="2026-02-13T02:26:25+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 13 02:26:25 volumio go-librespot[12851]: time="2026-02-13T02:26:25+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 13 02:26:25 volumio go-librespot[12851]: time="2026-02-13T02:26:25+07:00" level=info msg="zeroconf server listening on port 37557"
Feb 13 02:26:25 volumio volumio[12534]: error: MPD error: The expression evaluated to a falsy value:
Feb 13 02:26:25 volumio volumio[12534]: assert.ok(self.idling)
Feb 13 02:26:25 volumio volumio[12534]: error: The expression evaluated to a falsy value:
Feb 13 02:26:25 volumio volumio[12534]: assert.ok(self.idling)
Feb 13 02:26:25 volumio volumio[12534]: info: MPD running with PID12763
Feb 13 02:26:25 volumio volumio[12534]: ,establishing connection
Feb 13 02:26:25 volumio volumio[12534]: error: updateQueue error: null
Feb 13 02:26:25 volumio volumio[12534]: info: Completed starting Core Plugins
Feb 13 02:26:25 volumio volumio[12534]: info: -------------------------------------------
Feb 13 02:26:25 volumio volumio[12534]: info: ----- MyVolumio plugins startup ----
Feb 13 02:26:25 volumio volumio[12534]: info: -------------------------------------------
Feb 13 02:26:25 volumio volumio[12534]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 13 02:26:25 volumio volumio[12534]: error: updateQueue error: null
Feb 13 02:26:25 volumio go-librespot[12851]: time="2026-02-13T02:26:25+07:00" level=debug msg="obtained new client token: AADLICpmY9A9KxRgoRu4LJW/93m2kqC0r5TJGmZL2/tQR+WMBEssE5Uya7QlE9naEhwWiti2QPBLX9oKwednrBjeACsXG3CwHuR1Yy24t+D/k3Drc+7bnVPGtNtuLg5/tfKV3fD3ttORtQQBJkozhD0kVT3vn585nGfbh8Yc4v5ZcyxOuOfROQL6SjueUNCLcP9Cyyr0TilDrUP/4YL/vio7Zw1QBOUFAblBp1szagmm5h0RMA4NqyVwmg=="
Feb 13 02:26:26 volumio go-librespot[12851]: time="2026-02-13T02:26:26+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused"
Feb 13 02:26:26 volumio go-librespot[12851]: time="2026-02-13T02:26:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 13 02:26:26 volumio go-librespot[12851]: time="2026-02-13T02:26:26+07:00" level=debug msg="completed keyexchange"
Feb 13 02:26:26 volumio go-librespot[12851]: time="2026-02-13T02:26:26+07:00" level=debug msg="completed challenge"
Feb 13 02:26:26 volumio go-librespot[12851]: time="2026-02-13T02:26:26+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 02:26:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 02:26:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 02:26:28 volumio volumio[12534]: info: Initializing connection to go-librespot Websocket
Feb 13 02:26:28 volumio volumio[12534]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 02:26:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32.
Feb 13 02:26:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:26:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:26:29 volumio go-librespot[12864]: go-librespot daemon starting...
Feb 13 02:26:29 volumio go-librespot[12865]: time="2026-02-13T02:26:29+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 02:26:29 volumio go-librespot[12865]: time="2026-02-13T02:26:29+07:00" level=debug msg="app state loaded"
Feb 13 02:26:29 volumio go-librespot[12865]: time="2026-02-13T02:26:29+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 02:26:30 volumio go-librespot[12865]: time="2026-02-13T02:26:30+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 13 02:26:30 volumio go-librespot[12865]: time="2026-02-13T02:26:30+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Feb 13 02:26:30 volumio go-librespot[12865]: time="2026-02-13T02:26:30+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Feb 13 02:26:30 volumio go-librespot[12865]: time="2026-02-13T02:26:30+07:00" level=info msg="zeroconf server listening on port 34007"
Feb 13 02:26:30 volumio go-librespot[12865]: time="2026-02-13T02:26:30+07:00" level=debug msg="obtained new client token: AAB4SohRp4oPIf3jK7IdL1zf4OzqX5u7s54U3R16jTfXucOn7W2doGe+tTXFuYoqr8IEMY9Rl+nkhkBh94Z5nN236eeliXOwjUNS/YEE3T8tllUAJdCCeuGP3oFJIhuNjMKhtoD8k4cJhbljJ1Yys5gfWFbsmw5j2993763AptCAT0zYkn1mEdqtQYMdqKV/3pa9YADKLRKOn8BKDecBUNpdz0XbetNXVIPFed+n2kiZikZNwr1FsZ9MxQ=="
Feb 13 02:26:30 volumio go-librespot[12865]: time="2026-02-13T02:26:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 02:26:30 volumio go-librespot[12865]: time="2026-02-13T02:26:30+07:00" level=debug msg="completed keyexchange"
Feb 13 02:26:30 volumio go-librespot[12865]: time="2026-02-13T02:26:30+07:00" level=debug msg="completed challenge"
Feb 13 02:26:30 volumio volumio[12534]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory
Feb 13 02:26:30 volumio go-librespot[12865]: time="2026-02-13T02:26:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 02:26:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 02:26:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 02:26:31 volumio volumio[12534]: info: Initializing connection to go-librespot Websocket
Feb 13 02:26:31 volumio volumio[12534]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 13 02:26:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33.
Feb 13 02:26:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:26:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:26:33 volumio go-librespot[12874]: go-librespot daemon starting...
Feb 13 02:26:33 volumio go-librespot[12875]: time="2026-02-13T02:26:33+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 02:26:33 volumio go-librespot[12875]: time="2026-02-13T02:26:33+07:00" level=debug msg="app state loaded"
Feb 13 02:26:33 volumio go-librespot[12875]: time="2026-02-13T02:26:33+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 02:26:34 volumio volumio[12534]: info: Initializing connection to go-librespot Websocket
Feb 13 02:26:34 volumio go-librespot[12875]: time="2026-02-13T02:26:34+07:00" level=debug msg="new websocket client"
Feb 13 02:26:34 volumio volumio[12534]: info: Connection to go-librespot Websocket established
Feb 13 02:26:34 volumio go-librespot[12875]: time="2026-02-13T02:26:34+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 13 02:26:34 volumio go-librespot[12875]: time="2026-02-13T02:26:34+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Feb 13 02:26:34 volumio go-librespot[12875]: time="2026-02-13T02:26:34+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Feb 13 02:26:34 volumio go-librespot[12875]: time="2026-02-13T02:26:34+07:00" level=info msg="zeroconf server listening on port 32877"
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Feb 13 02:26:34 volumio go-librespot[12875]: time="2026-02-13T02:26:34+07:00" level=debug msg="obtained new client token: AAAfPEDxdid324/+arSTMxG+JQ8gRw6TmK/SHuSKifFsckse7WMU2sygm0E+tNIaS3BJtpG+fhqLF0i6NsqvU4At4rIT1YAeTuyz1srBziGtltNjoVdZ9JaqKZF06YTxcZw+I6SP8yEBQ5qr1yaKMbOu71+Nx5VFyRTG0Ji+VBFIBD1qvzjXPPZNBaqf3hapqgT5/5qO+SZcKi4CbGo0hNtYu7KpiN96ESE/1wcIVk9D/uo1WVUwtdFlPw=="
Feb 13 02:26:34 volumio volumio[12534]: info: Adding plugin bluetooth to MyMusic Plugins
Feb 13 02:26:34 volumio volumio[12534]: info: Adding plugin multiroom to MyMusic Plugins
Feb 13 02:26:34 volumio volumio[12534]: info: Adding plugin metavolumio to MyMusic Plugins
Feb 13 02:26:34 volumio volumio[12534]: info: Adding plugin cd_controller to MyMusic Plugins
Feb 13 02:26:34 volumio volumio[12534]: info: Adding plugin qobuzconnect to MyMusic Plugins
Feb 13 02:26:34 volumio volumio[12534]: info: Adding plugin smart_inputs to MyMusic Plugins
Feb 13 02:26:34 volumio volumio[12534]: info: Adding plugin tidalconnect to MyMusic Plugins
Feb 13 02:26:34 volumio volumio[12534]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Feb 13 02:26:34 volumio go-librespot[12875]: time="2026-02-13T02:26:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 02:26:34 volumio go-librespot[12875]: time="2026-02-13T02:26:34+07:00" level=debug msg="completed keyexchange"
Feb 13 02:26:34 volumio go-librespot[12875]: time="2026-02-13T02:26:34+07:00" level=debug msg="completed challenge"
Feb 13 02:26:34 volumio go-librespot[12875]: time="2026-02-13T02:26:34+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 02:26:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 02:26:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 02:26:36 volumio volumio[12534]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Feb 13 02:26:36 volumio volumio[12534]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Feb 13 02:26:36 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 02:26:36 volumio volumio[12534]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 13 02:26:36 volumio volumio[12534]: info: Starting MyVolumio Remote Streaming Endpoints
Feb 13 02:26:36 volumio volumio[12534]: info: MyVolumio login type: Token
Feb 13 02:26:36 volumio volumio[12534]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Feb 13 02:26:36 volumio volumio[12534]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Feb 13 02:26:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34.
Feb 13 02:26:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:26:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 13 02:26:38 volumio go-librespot[12896]: go-librespot daemon starting...
Feb 13 02:26:38 volumio go-librespot[12897]: time="2026-02-13T02:26:38+07:00" level=info msg="running go-librespot 0.4.0"
Feb 13 02:26:38 volumio go-librespot[12897]: time="2026-02-13T02:26:38+07:00" level=debug msg="app state loaded"
Feb 13 02:26:38 volumio go-librespot[12897]: time="2026-02-13T02:26:38+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 13 02:26:38 volumio volumio[12534]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Feb 13 02:26:38 volumio volumio[12534]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Feb 13 02:26:38 volumio volumio[12534]: info: Streaming services startup
Feb 13 02:26:38 volumio volumio[12534]: info: Starting Streaming Daemon
Feb 13 02:26:38 volumio sudo[12904]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 13 02:26:38 volumio sudo[12904]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 13 02:26:38 volumio volumio[12534]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Feb 13 02:26:38 volumio sudo[12904]: pam_unix(sudo:session): session closed for user root
Feb 13 02:26:38 volumio volumio[12534]: info: Getting Spotify volume
Feb 13 02:26:38 volumio volumio[12534]: info: Connection to go-librespot Websocket closed
Feb 13 02:26:38 volumio volumio[12534]: error: Cannot start Volumio Streaming Daemon
Feb 13 02:26:38 volumio volumio[12534]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 13 02:26:38 volumio volumio[12534]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 13 02:26:38 volumio volumio[12534]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3
Feb 13 02:26:38 volumio go-librespot[12897]: time="2026-02-13T02:26:38+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 13 02:26:38 volumio go-librespot[12897]: time="2026-02-13T02:26:38+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 13 02:26:38 volumio go-librespot[12897]: time="2026-02-13T02:26:38+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 13 02:26:38 volumio go-librespot[12897]: time="2026-02-13T02:26:38+07:00" level=info msg="zeroconf server listening on port 38455"
Feb 13 02:26:38 volumio volumio[12534]: info: CoreCommandRouter::volumioGetState
Feb 13 02:26:38 volumio volumio[12534]: info: CorePlayQueue::getTrack 0
Feb 13 02:26:38 volumio volumio[12534]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 13 02:26:38 volumio volumio[12534]: SPOTIFY: SPOTIFY VOLUME undefined
Feb 13 02:26:38 volumio volumio[12534]: SPOTIFY: VOLUMIO VOLUME 100
Feb 13 02:26:38 volumio volumio[12534]: info: Aligning Spotify Volume to Volumio Volume
Feb 13 02:26:38 volumio volumio[12534]: info: CoreCommandRouter::volumioGetState
Feb 13 02:26:38 volumio volumio[12534]: info: CorePlayQueue::getTrack 0
Feb 13 02:26:38 volumio volumio[12534]: info: Setting Spotify Volume from Volumio: 100
Feb 13 02:26:38 volumio go-librespot[12897]: time="2026-02-13T02:26:38+07:00" level=debug msg="obtained new client token: AACwkeeAmGYWESbjWOnzj62gCwvuf8Ewepba5/zOtnZwe2REc34fjhTTGClOIb05CrXnrvxHQdndw9yPDV0sYN+vhByoGrzlsnnG0Gf0LQLBhEJsQtLd+gN1NF7+vk4KREPPDjwd4156Wo9fE093BhVtFwTieewJtZsjdS9tOpQdC/kK/d06+ve8hU3nj6QIUTeOJcjwhUt8fbKLyM+NF4VoACBEhwnix8D4Mzcx8NPE5yYsj/7HNbgGLg=="
Feb 13 02:26:39 volumio go-librespot[12897]: time="2026-02-13T02:26:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 13 02:26:39 volumio go-librespot[12897]: time="2026-02-13T02:26:39+07:00" level=debug msg="completed keyexchange"
Feb 13 02:26:39 volumio go-librespot[12897]: time="2026-02-13T02:26:39+07:00" level=debug msg="completed challenge"
Feb 13 02:26:39 volumio go-librespot[12897]: time="2026-02-13T02:26:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 13 02:26:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 13 02:26:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 13 02:26:39 volumio volumio[12534]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 13 02:26:39 volumio volumio[12534]: Error: socket hang up
Feb 13 02:26:39 volumio volumio[12534]: at connResetException (node:internal/errors:720:14)
Feb 13 02:26:39 volumio volumio[12534]: at Socket.socketOnEnd (node:_http_client:519:23)
Feb 13 02:26:39 volumio volumio[12534]: at Socket.emit (node:events:526:35)
Feb 13 02:26:39 volumio volumio[12534]: at endReadableNT (node:internal/streams/readable:1376:12)
Feb 13 02:26:39 volumio volumio[12534]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
Feb 13 02:26:39 volumio volumio[12534]: code: 'ECONNRESET',
Feb 13 02:26:39 volumio volumio[12534]: response: undefined
Feb 13 02:26:39 volumio volumio[12534]: }
Feb 13 02:26:39 volumio volumio[12534]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 13 02:26:40 volumio sudo[12926]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-13 02:25'
Feb 13 02:26:40 volumio sudo[12926]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)"
NAME="Raspbian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025"
VOLUMIO_VERSION="4.084"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"