Jan 26 23:08:00 volumio volumio[21360]: info: Initializing connection to go-librespot Websocket Jan 26 23:08:00 volumio volumio[21360]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 23:08:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Jan 26 23:08:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:08:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:08:01 volumio go-librespot[21690]: go-librespot daemon starting... Jan 26 23:08:01 volumio go-librespot[21691]: time="2026-01-26T23:08:01+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 23:08:01 volumio go-librespot[21691]: time="2026-01-26T23:08:01+07:00" level=debug msg="app state loaded" Jan 26 23:08:01 volumio go-librespot[21691]: time="2026-01-26T23:08:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 23:08:01 volumio go-librespot[21691]: time="2026-01-26T23:08: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-gew4.spotify.com:80]" Jan 26 23:08:01 volumio go-librespot[21691]: time="2026-01-26T23:08:01+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]" Jan 26 23:08:01 volumio go-librespot[21691]: time="2026-01-26T23:08:01+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]" Jan 26 23:08:01 volumio go-librespot[21691]: time="2026-01-26T23:08:01+07:00" level=info msg="zeroconf server listening on port 36203" Jan 26 23:08:02 volumio go-librespot[21691]: time="2026-01-26T23:08:02+07:00" level=debug msg="obtained new client token: AAA7rtw+jSAGkgOozSru0pRjbvXi/yM/G+FiwbVOAF7a57XyUTrUmk71mEPRPTcyLS41VFfpaNNaCqqaL34GRw83uyBH9MXbvdW+BAbe/wCUQ6slgIfNEM2G1Nr0biQrF08+o+F7csZqJyeqAHSkb6m9Uz2b4lNylCfbDVZr3APruk/1opIeF1ORxNUWKBSZmzHpG3FM1NHppaCbuqpYhBQKHgPZtmWVfaMWXi7PtC04S9Khyr9MndW/" Jan 26 23:08:02 volumio go-librespot[21691]: time="2026-01-26T23:08:02+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" Jan 26 23:08:02 volumio go-librespot[21691]: time="2026-01-26T23:08:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 26 23:08:02 volumio go-librespot[21691]: time="2026-01-26T23:08:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 23:08:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 23:08:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 23:08:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:03 volumio volumio[21360]: info: Initializing connection to go-librespot Websocket Jan 26 23:08:03 volumio volumio[21360]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 23:08:03 volumio volumio[21360]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 26 23:08:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Jan 26 23:08:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:08:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:08:05 volumio go-librespot[21698]: go-librespot daemon starting... Jan 26 23:08:05 volumio go-librespot[21699]: time="2026-01-26T23:08:05+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 23:08:05 volumio go-librespot[21699]: time="2026-01-26T23:08:05+07:00" level=debug msg="app state loaded" Jan 26 23:08:05 volumio go-librespot[21699]: time="2026-01-26T23:08:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 23:08:06 volumio volumio[21360]: info: Initializing connection to go-librespot Websocket Jan 26 23:08:06 volumio go-librespot[21699]: time="2026-01-26T23:08:06+07:00" level=debug msg="new websocket client" Jan 26 23:08:06 volumio volumio[21360]: info: Connection to go-librespot Websocket established Jan 26 23:08:06 volumio go-librespot[21699]: time="2026-01-26T23:08:06+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]" Jan 26 23:08:06 volumio go-librespot[21699]: time="2026-01-26T23:08:06+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]" Jan 26 23:08:06 volumio go-librespot[21699]: time="2026-01-26T23:08:06+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]" Jan 26 23:08:06 volumio go-librespot[21699]: time="2026-01-26T23:08:06+07:00" level=info msg="zeroconf server listening on port 36663" Jan 26 23:08:06 volumio go-librespot[21699]: time="2026-01-26T23:08:06+07:00" level=debug msg="obtained new client token: AAApcCeTYOtsxLaj/H2TZAIl0wI0EfmTluzZuP+Lhrytbdg3l+Pt+mm4sCNDtA//SkHVeE7bTN8NB4LCFCjCTfnjILOn1X15DGj3ZOhsxHP/SCixFg0KjhDUyc4pQxWmq5/atgtZsrDFxh/kpxeZ4rYaD5Szsz+zIHAd/axrWxR9WzM9Gd+lYd9dsWO6vMC4yQM9g2L5j+2skuNAxwEgV+WRZQ+rWIEwgaYqmEQn57He8PX/c/euL6CpvvQ=" Jan 26 23:08:06 volumio go-librespot[21699]: time="2026-01-26T23:08:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 23:08:06 volumio go-librespot[21699]: time="2026-01-26T23:08:06+07:00" level=debug msg="completed keyexchange" Jan 26 23:08:06 volumio go-librespot[21699]: time="2026-01-26T23:08:06+07:00" level=debug msg="completed challenge" Jan 26 23:08:06 volumio go-librespot[21699]: time="2026-01-26T23:08: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 " Jan 26 23:08:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 23:08:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 23:08:06 volumio volumio[21360]: info: Connection to go-librespot Websocket closed Jan 26 23:08:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 26 23:08:07 volumio volumio[21360]: info: Adding plugin bluetooth to MyMusic Plugins Jan 26 23:08:07 volumio volumio[21360]: info: Adding plugin multiroom to MyMusic Plugins Jan 26 23:08:07 volumio volumio[21360]: info: Adding plugin metavolumio to MyMusic Plugins Jan 26 23:08:07 volumio volumio[21360]: info: Adding plugin cd_controller to MyMusic Plugins Jan 26 23:08:07 volumio volumio[21360]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 26 23:08:07 volumio volumio[21360]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 26 23:08:07 volumio volumio[21360]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 26 23:08:07 volumio volumio[21360]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 26 23:08:08 volumio volumio[21360]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 26 23:08:08 volumio volumio[21360]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 26 23:08:08 volumio volumio[21360]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 23:08:08 volumio volumio[21360]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 23:08:08 volumio volumio[21360]: info: Starting MyVolumio Remote Streaming Endpoints Jan 26 23:08:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:08 volumio volumio[21360]: info: MyVolumio login type: Token Jan 26 23:08:09 volumio volumio[21360]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 26 23:08:09 volumio volumio[21360]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 26 23:08:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 26 23:08:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:08:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:08:10 volumio go-librespot[21721]: go-librespot daemon starting... Jan 26 23:08:10 volumio go-librespot[21722]: time="2026-01-26T23:08:10+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 23:08:10 volumio go-librespot[21722]: time="2026-01-26T23:08:10+07:00" level=debug msg="app state loaded" Jan 26 23:08:10 volumio go-librespot[21722]: time="2026-01-26T23:08:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 23:08:10 volumio go-librespot[21722]: time="2026-01-26T23:08:10+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]" Jan 26 23:08:10 volumio go-librespot[21722]: time="2026-01-26T23:08:10+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]" Jan 26 23:08:10 volumio go-librespot[21722]: time="2026-01-26T23:08:10+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]" Jan 26 23:08:10 volumio go-librespot[21722]: time="2026-01-26T23:08:10+07:00" level=info msg="zeroconf server listening on port 39089" Jan 26 23:08:10 volumio volumio[21360]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 26 23:08:10 volumio volumio[21360]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 26 23:08:10 volumio volumio[21360]: info: Streaming services startup Jan 26 23:08:10 volumio volumio[21360]: info: Starting Streaming Daemon Jan 26 23:08:10 volumio volumio[21360]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 26 23:08:10 volumio sudo[21730]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 26 23:08:10 volumio sudo[21730]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:08:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:10 volumio sudo[21730]: pam_unix(sudo:session): session closed for user root Jan 26 23:08:10 volumio go-librespot[21722]: time="2026-01-26T23:08:10+07:00" level=debug msg="obtained new client token: AADptryH2/O+BlD21acm22+4Gtb2AT6977oxUw+VQU6KqpvK+PGVNKhm50IzOFATzkFcgjuOfE2qQZT4OUUnKse9vPSnJxC/qz4U23Wu4ltHN040iG6GbzBBY5N9hoWnzQSCrOa590Fe/68jBhun2uCqc8Jw8a9gxFUcCNMJwvlMprBeVWaRL/xuEI5MAjHqB86mWFaE75J3Dk0Ai85Z9Md6FjJFZmNHAxv54kyG+WUYY/gaNJp+EsB4VFI=" Jan 26 23:08:11 volumio volumio[21360]: info: Getting Spotify volume Jan 26 23:08:11 volumio volumio[21360]: info: Initializing connection to go-librespot Websocket Jan 26 23:08:11 volumio go-librespot[21722]: time="2026-01-26T23:08:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 23:08:11 volumio volumio[21360]: error: Cannot start Volumio Streaming Daemon Jan 26 23:08:11 volumio volumio[21360]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 26 23:08:11 volumio volumio[21360]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 26 23:08:11 volumio go-librespot[21722]: time="2026-01-26T23:08:11+07:00" level=debug msg="new websocket client" Jan 26 23:08:11 volumio go-librespot[21722]: time="2026-01-26T23:08:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 23:08:11 volumio volumio[21360]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 26 23:08:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 23:08:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 23:08:11 volumio volumio[21360]: info: Connection to go-librespot Websocket established Jan 26 23:08:11 volumio volumio[21360]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 23:08:11 volumio volumio[21360]: Error: socket hang up Jan 26 23:08:11 volumio volumio[21360]: at connResetException (node:internal/errors:720:14) Jan 26 23:08:11 volumio volumio[21360]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 26 23:08:11 volumio volumio[21360]: at Socket.emit (node:events:526:35) Jan 26 23:08:11 volumio volumio[21360]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 26 23:08:11 volumio volumio[21360]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 26 23:08:11 volumio volumio[21360]: code: 'ECONNRESET', Jan 26 23:08:11 volumio volumio[21360]: response: undefined Jan 26 23:08:11 volumio volumio[21360]: } Jan 26 23:08:11 volumio volumio[21360]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 23:08:12 volumio sudo[21750]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-26 23:07' Jan 26 23:08:12 volumio sudo[21750]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:08:12 volumio sudo[21750]: pam_unix(sudo:session): session closed for user root Jan 26 23:08:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 26 23:08:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:08:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:08:14 volumio go-librespot[21758]: go-librespot daemon starting... Jan 26 23:08:14 volumio go-librespot[21759]: time="2026-01-26T23:08:14+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 23:08:14 volumio go-librespot[21759]: time="2026-01-26T23:08:14+07:00" level=debug msg="app state loaded" Jan 26 23:08:14 volumio go-librespot[21759]: time="2026-01-26T23:08:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 23:08:14 volumio volumio-remote-updater[628]: [2026-01-26 23:08:14] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Jan 26 23:08:14 volumio volumio-remote-updater[628]: [2026-01-26 23:08:14] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Jan 26 23:08:14 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 26 23:08:14 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 26 23:08:14 volumio systemd[1]: volumio.service: Consumed 1min 10.126s CPU time. Jan 26 23:08:14 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 26 23:08:14 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 26 23:08:14 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 7682. Jan 26 23:08:14 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 26 23:08:14 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 26 23:08:14 volumio systemd[1]: volumio.service: Consumed 1min 10.126s CPU time. Jan 26 23:08:14 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 26 23:08:14 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 26 23:08:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:14 volumio go-librespot[21759]: time="2026-01-26T23:08: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 23:08:14 volumio go-librespot[21759]: time="2026-01-26T23:08:14+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]" Jan 26 23:08:14 volumio go-librespot[21759]: time="2026-01-26T23:08:14+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]" Jan 26 23:08:14 volumio go-librespot[21759]: time="2026-01-26T23:08:14+07:00" level=info msg="zeroconf server listening on port 45511" Jan 26 23:08:15 volumio go-librespot[21759]: time="2026-01-26T23:08:15+07:00" level=debug msg="obtained new client token: AAB6KRQM0MdgFdZ/EOkExuIIrFIugj5o7iGrJJJg7vdKqIyyCQekF/fntPaN5lxCgT8egxFuw8jyNac0MliVc+/7QKLDd3k9QK7hWoW2mPM8V6glMxmFNU+jm3Zs5Gq4AZJODW7XO2E3URQXv+haNyNe1QGteDpY88wpxnddICIDwsTzKXqgr5wZzqBazWp6M/tsS/0jZjvgTANhITP+JRcrl86tyxFNEVXtnwnM5phdDHRzbLzoL+Fm" Jan 26 23:08:15 volumio go-librespot[21759]: time="2026-01-26T23:08:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 23:08:15 volumio go-librespot[21759]: time="2026-01-26T23:08:15+07:00" level=debug msg="completed keyexchange" Jan 26 23:08:15 volumio go-librespot[21759]: time="2026-01-26T23:08:15+07:00" level=debug msg="completed challenge" Jan 26 23:08:15 volumio go-librespot[21759]: time="2026-01-26T23:08:15+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 " Jan 26 23:08:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 23:08:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 23:08:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:18 volumio volumio[21773]: info: ------------------------------------------- Jan 26 23:08:18 volumio volumio[21773]: info: ----- Volumio3 ---- Jan 26 23:08:18 volumio volumio[21773]: info: ------------------------------------------- Jan 26 23:08:18 volumio volumio[21773]: info: ----- System startup ---- Jan 26 23:08:18 volumio volumio[21773]: info: ------------------------------------------- Jan 26 23:08:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jan 26 23:08:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:08:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:08:18 volumio go-librespot[21794]: go-librespot daemon starting... Jan 26 23:08:18 volumio go-librespot[21795]: time="2026-01-26T23:08:18+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 23:08:18 volumio go-librespot[21795]: time="2026-01-26T23:08:18+07:00" level=debug msg="app state loaded" Jan 26 23:08:18 volumio go-librespot[21795]: time="2026-01-26T23:08:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 23:08:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:19 volumio go-librespot[21795]: time="2026-01-26T23:08:19+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]" Jan 26 23:08:19 volumio go-librespot[21795]: time="2026-01-26T23:08:19+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]" Jan 26 23:08:19 volumio go-librespot[21795]: time="2026-01-26T23:08:19+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]" Jan 26 23:08:19 volumio go-librespot[21795]: time="2026-01-26T23:08:19+07:00" level=info msg="zeroconf server listening on port 43983" Jan 26 23:08:19 volumio volumio-remote-updater[628]: [2026-01-26 23:08:19] [connect] Successful connection Jan 26 23:08:19 volumio go-librespot[21795]: time="2026-01-26T23:08:19+07:00" level=debug msg="obtained new client token: AAC179hTqstMVljflypbC3hmV859O4c5c0XgDlIBNgbSvGHmGryyvNXK/hAMQiUp1D3Y58yxf6k0/0d+lB24X9BJOqJse27pk0ZrNXOMEEAat/ZD9swU9Ux2g19MTWa4eh2B8TmJo6VGem+QJsHu9QCXp3zLt8YKXQ5x8NYvBNyCXM25WTCfSIGa+JWespXh9gaL5H6/+NmoH/klnQbXROoJKT7993SAKTN701o0PxEaL70uljYejCDjnxY=" Jan 26 23:08:19 volumio go-librespot[21795]: time="2026-01-26T23:08:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 23:08:19 volumio go-librespot[21795]: time="2026-01-26T23:08:19+07:00" level=debug msg="completed keyexchange" Jan 26 23:08:19 volumio go-librespot[21795]: time="2026-01-26T23:08:19+07:00" level=debug msg="completed challenge" Jan 26 23:08:19 volumio volumio[21773]: info: MYVOLUMIO Environment detected Jan 26 23:08:19 volumio go-librespot[21795]: time="2026-01-26T23:08: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 " Jan 26 23:08:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 23:08:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 23:08:19 volumio volumio[21773]: info: Plugin folders cleanup Jan 26 23:08:19 volumio volumio[21773]: info: Scanning into folder /volumio/app/plugins/ Jan 26 23:08:19 volumio volumio[21773]: info: Scanning category audio_interface Jan 26 23:08:19 volumio volumio[21773]: info: Scanning category miscellanea Jan 26 23:08:19 volumio volumio[21773]: info: Scanning category music_service Jan 26 23:08:19 volumio volumio[21773]: info: Scanning category plugins.json Jan 26 23:08:19 volumio volumio[21773]: info: Scanning category system_controller Jan 26 23:08:19 volumio volumio[21773]: info: Scanning category user_interface Jan 26 23:08:19 volumio volumio[21773]: info: Scanning into folder /data/plugins/ Jan 26 23:08:19 volumio volumio[21773]: info: Scanning category music_service Jan 26 23:08:19 volumio volumio[21773]: info: Plugin folders cleanup completed Jan 26 23:08:19 volumio volumio[21773]: info: ------------------------------------------- Jan 26 23:08:19 volumio volumio[21773]: info: ----- Core plugins startup ---- Jan 26 23:08:19 volumio volumio[21773]: info: ------------------------------------------- Jan 26 23:08:19 volumio volumio[21773]: info: Loading plugins from folder /volumio/app/plugins/ Jan 26 23:08:19 volumio volumio[21773]: info: Adding plugin upnp to MyMusic Plugins Jan 26 23:08:19 volumio volumio[21773]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 26 23:08:19 volumio volumio[21773]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 26 23:08:19 volumio volumio[21773]: info: Loading plugins from folder /data/plugins/ Jan 26 23:08:19 volumio volumio[21773]: info: Loading plugin "system"... Jan 26 23:08:19 volumio volumio[21773]: info: Loading plugin "appearance"... Jan 26 23:08:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:21 volumio volumio[21773]: info: Loading plugin "network"... Jan 26 23:08:21 volumio volumio[21773]: info: Refreshing Cached IP Addresses Jan 26 23:08:21 volumio sudo[21813]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 23:08:21 volumio sudo[21813]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:08:21 volumio sudo[21813]: pam_unix(sudo:session): session closed for user root Jan 26 23:08:21 volumio sudo[21815]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 23:08:21 volumio volumio[21773]: info: Loading plugin "services"... Jan 26 23:08:21 volumio sudo[21815]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:08:21 volumio volumio[21773]: info: Loading plugin "alsa_controller"... Jan 26 23:08:21 volumio sudo[21815]: pam_unix(sudo:session): session closed for user root Jan 26 23:08:21 volumio sudo[21827]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 26 23:08:21 volumio sudo[21827]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:08:22 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 23:08:22 volumio volumio[21773]: info: Loading plugin "wizard"... Jan 26 23:08:22 volumio volumio[21773]: info: Loading plugin "networkfs"... Jan 26 23:08:22 volumio volumio[21773]: info: Starting Udev Watcher for removable devices Jan 26 23:08:22 volumio volumio[21773]: info: Ignoring mount for partition: boot Jan 26 23:08:22 volumio volumio[21773]: info: Ignoring mount for partition: volumio Jan 26 23:08:22 volumio volumio[21773]: info: Ignoring mount for partition: volumio_data Jan 26 23:08:22 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 23:08:22 volumio volumio[21773]: info: Loading plugin "volumio_command_line_client"... Jan 26 23:08:22 volumio volumio[21773]: info: Loading plugin "upnp"... Jan 26 23:08:22 volumio volumio[21773]: info: [1769443702196] Starting Upmpd Daemon Jan 26 23:08:22 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 23:08:22 volumio volumio[21773]: info: Loading plugin "my_music"... Jan 26 23:08:22 volumio volumio[21773]: info: Loading plugin "mpd"... Jan 26 23:08:22 volumio volumio[21773]: info: Loading plugin "upnp_browser"... Jan 26 23:08:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Jan 26 23:08:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:08:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:08:23 volumio go-librespot[21846]: go-librespot daemon starting... Jan 26 23:08:23 volumio go-librespot[21847]: time="2026-01-26T23:08:23+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 23:08:23 volumio go-librespot[21847]: time="2026-01-26T23:08:23+07:00" level=debug msg="app state loaded" Jan 26 23:08:23 volumio go-librespot[21847]: time="2026-01-26T23:08:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 23:08:23 volumio go-librespot[21847]: time="2026-01-26T23:08:23+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]" Jan 26 23:08:23 volumio go-librespot[21847]: time="2026-01-26T23:08:23+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]" Jan 26 23:08:23 volumio go-librespot[21847]: time="2026-01-26T23:08:23+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]" Jan 26 23:08:23 volumio go-librespot[21847]: time="2026-01-26T23:08:23+07:00" level=info msg="zeroconf server listening on port 45103" Jan 26 23:08:23 volumio go-librespot[21847]: time="2026-01-26T23:08:23+07:00" level=debug msg="obtained new client token: AACP2gbwXr7YneNRho3HGbos7JgZryxePqTSyHj298tYHgF0t7OxKNB/s5U/O/AP8DAJQZCIukHBrj5K6pQri9irkYr93MCWO23n1J7ro5iEltOlhW5BFeyHvqXn8ddy5HPGwNhDnEA7HBWk5IApuGg+rENXlHKgSLRt6lko0SNRtyLXCDHchjTCFdDpr6eFeL4YoD/wc8i/MOYNBF9KWx4/ajEJaeAsHlHpX75o3ZilGegSs69lOV50gtA=" Jan 26 23:08:24 volumio go-librespot[21847]: time="2026-01-26T23:08:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 23:08:24 volumio go-librespot[21847]: time="2026-01-26T23:08:24+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 23:08:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 23:08:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 23:08:24 volumio sudo[21827]: pam_unix(sudo:session): session closed for user root Jan 26 23:08:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:25 volumio volumio[21773]: info: Starting UPNP Browser Jan 26 23:08:25 volumio volumio[21773]: info: Loading plugin "alarm-clock"... Jan 26 23:08:26 volumio volumio[21773]: info: Loading plugin "airplay_emulation"... Jan 26 23:08:26 volumio volumio[21773]: info: Starting Shairport Sync Jan 26 23:08:26 volumio volumio[21773]: info: Loading plugin "last_100"... Jan 26 23:08:26 volumio volumio[21773]: info: Loading plugin "webradio"... Jan 26 23:08:26 volumio volumio[21773]: info: Loading plugin "i2s_dacs"... Jan 26 23:08:26 volumio volumio[21773]: info: Loading plugin "volumiodiscovery"... Jan 26 23:08:26 volumio volumio[21773]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 23:08:26 volumio volumio[21773]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 23:08:26 volumio node[21773]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 23:08:26 volumio volumio[21773]: *** WARNING *** For more information see Jan 26 23:08:26 volumio volumio[21773]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 23:08:26 volumio volumio[21773]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 23:08:26 volumio volumio[21773]: *** WARNING *** For more information see Jan 26 23:08:26 volumio node[21773]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 23:08:26 volumio node[21773]: *** WARNING *** For more information see Jan 26 23:08:26 volumio node[21773]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 23:08:26 volumio node[21773]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 23:08:26 volumio node[21773]: *** WARNING *** For more information see Jan 26 23:08:26 volumio volumio[21773]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 26 23:08:26 volumio volumio[21773]: info: Discovery: Started advertising with name: Volumio Jan 26 23:08:26 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 23:08:26 volumio volumio[21773]: info: Loading plugin "spop"... Jan 26 23:08:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Jan 26 23:08:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:08:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:08:27 volumio go-librespot[21856]: go-librespot daemon starting... Jan 26 23:08:27 volumio go-librespot[21857]: time="2026-01-26T23:08:27+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 23:08:27 volumio go-librespot[21857]: time="2026-01-26T23:08:27+07:00" level=debug msg="app state loaded" Jan 26 23:08:27 volumio go-librespot[21857]: time="2026-01-26T23:08:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 23:08:27 volumio go-librespot[21857]: time="2026-01-26T23:08: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 23:08:27 volumio go-librespot[21857]: time="2026-01-26T23:08:27+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]" Jan 26 23:08:27 volumio go-librespot[21857]: time="2026-01-26T23:08:27+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]" Jan 26 23:08:27 volumio go-librespot[21857]: time="2026-01-26T23:08:27+07:00" level=info msg="zeroconf server listening on port 35911" Jan 26 23:08:28 volumio go-librespot[21857]: time="2026-01-26T23:08:28+07:00" level=debug msg="obtained new client token: AADw/VDL7so212EotX+xWj7cKph3nN8yRFOa5cs9ukI7Szmp90jzWFIWX5dIQz1oVBmSxYCNlmBPwZXzZmAxQ5j73vA3s9MQRDT74CJMbKrvb31DimiNAT95JMqSHIm1BV7GUc8K8rfdO5cv9j0p8NPog4YyFgF06Wtgg3jETQCNGOyQ0ZFAJlcGHZnE+fivXZqEeoq8xosOiW3ULAm6DRUpwjmiRxkLfFnv85CqQC6k9tvVn08iCXEJ" Jan 26 23:08:28 volumio go-librespot[21857]: time="2026-01-26T23:08:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 23:08:28 volumio go-librespot[21857]: time="2026-01-26T23:08:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 23:08:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 23:08:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 23:08:28 volumio volumio[21773]: info: Loading plugin "ytcr"... Jan 26 23:08:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:30 volumio volumio[21773]: info: Loading plugin "ytmusic"... Jan 26 23:08:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Jan 26 23:08:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:08:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:08:31 volumio go-librespot[21864]: go-librespot daemon starting... Jan 26 23:08:31 volumio go-librespot[21865]: time="2026-01-26T23:08:31+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 23:08:31 volumio go-librespot[21865]: time="2026-01-26T23:08:31+07:00" level=debug msg="app state loaded" Jan 26 23:08:31 volumio go-librespot[21865]: time="2026-01-26T23:08:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 23:08:31 volumio volumio-remote-updater[628]: [2026-01-26 23:08:31] [connect] Successful connection Jan 26 23:08:32 volumio volumio[21773]: info: Loading plugin "outputs"... Jan 26 23:08:32 volumio volumio[21773]: info: Loading plugin "albumart"... Jan 26 23:08:32 volumio volumio[21773]: info: Plugin example_plugin is not enabled Jan 26 23:08:32 volumio volumio[21773]: info: Loading plugin "inputs"... Jan 26 23:08:32 volumio volumio[21773]: info: Loading plugin "updater_comm"... Jan 26 23:08:32 volumio go-librespot[21865]: time="2026-01-26T23:08:32+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]" Jan 26 23:08:32 volumio go-librespot[21865]: time="2026-01-26T23:08:32+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]" Jan 26 23:08:32 volumio go-librespot[21865]: time="2026-01-26T23:08:32+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]" Jan 26 23:08:32 volumio go-librespot[21865]: time="2026-01-26T23:08:32+07:00" level=info msg="zeroconf server listening on port 39205" Jan 26 23:08:32 volumio volumio[21773]: info: Plugin mpdemulation is not enabled Jan 26 23:08:32 volumio volumio[21773]: info: Loading plugin "rest_api"... Jan 26 23:08:32 volumio volumio[21773]: info: Loading plugin "websocket"... Jan 26 23:08:32 volumio volumio[21773]: info: Starting Socket.io Server version 1.7.4 Jan 26 23:08:32 volumio volumio[21773]: info: Loading plugin "RoonBridge"... Jan 26 23:08:32 volumio go-librespot[21865]: time="2026-01-26T23:08:32+07:00" level=debug msg="obtained new client token: AAAqwl1PuZ/OvBdn71No9Xr3tyOHzwJSrWg9ffD5rhRLBvNBqdJqU82USagmyoi0/wGriv4f45Is74GFh6l3t3hQtu8rhBWpBlP4yZxS7vAx5+7jD4TXsn/dB6UZhM2SPOxmgHHocTlCvhC/rnUU6am8fBRtSXU12qJTxquK0TOe7xn08Xr+sna9f4iuPqXz+VtzXVBoQy5bmdYC05ZqMRDLvtMpgrKgfeEsa8tpbUgyrhVtidUwMij8pnE=" Jan 26 23:08:32 volumio go-librespot[21865]: time="2026-01-26T23:08:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 23:08:32 volumio go-librespot[21865]: time="2026-01-26T23:08:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 23:08:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 23:08:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 23:08:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:33 volumio volumio[21773]: info: Applying required configuration parameters for plugin RoonBridge Jan 26 23:08:33 volumio volumio[21773]: info: Loading i18n strings for locale en Jan 26 23:08:33 volumio volumio[21773]: Updating browse sources language Jan 26 23:08:33 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 23:08:33 volumio volumio[21886]: Forking 3 albumart workers Jan 26 23:08:33 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 23:08:33 volumio volumio[21773]: info: CoreCommandRouter::initPlayerControls Jan 26 23:08:33 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:33 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:33 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:33 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:33 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:33 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:33 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:33 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:33 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 23:08:33 volumio volumio[21773]: Express server listening on port 3000 Jan 26 23:08:33 volumio volumio[21773]: [Metrics] WebUI: 16s 84.63ms Jan 26 23:08:33 volumio volumio[21773]: info: CoreStateMachine::resetVolumioState Jan 26 23:08:33 volumio volumio[21773]: info: CoreStateMachine::getcurrentVolume Jan 26 23:08:33 volumio volumio[21773]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 23:08:33 volumio sudo[21929]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 23:08:33 volumio sudo[21929]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:08:33 volumio sudo[21929]: pam_unix(sudo:session): session closed for user root Jan 26 23:08:33 volumio sudo[21932]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 23:08:33 volumio sudo[21932]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:08:33 volumio sudo[21932]: pam_unix(sudo:session): session closed for user root Jan 26 23:08:33 volumio volumio[21773]: info: Volumio Network Manager: Network status updated: 1 Jan 26 23:08:33 volumio volumio[21773]: info: VolumeController:: Volume=100 Mute =false Jan 26 23:08:33 volumio volumio[21773]: info: CoreStateMachine::pushState Jan 26 23:08:33 volumio volumio[21773]: info: CorePlayQueue::getTrack 0 Jan 26 23:08:33 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 23:08:33 volumio volumio[21773]: info: CoreCommandRouter::volumioPushState Jan 26 23:08:33 volumio volumio[21773]: info: CoreStateMachine::updateTrackBlock Jan 26 23:08:33 volumio volumio[21773]: info: CorePlayQueue::getTrackBlock Jan 26 23:08:33 volumio volumio[21773]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 23:08:34 volumio volumio-remote-updater[628]: [2026-01-26 23:08:34] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769443711 101 Jan 26 23:08:34 volumio volumio[21773]: 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 Jan 26 23:08:34 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 23:08:34 volumio volumio[21773]: info: Reloading queue from file Jan 26 23:08:34 volumio volumio[21773]: info: CoreStateMachine::setRepeat null single undefined Jan 26 23:08:34 volumio volumio[21773]: info: CoreStateMachine::pushState Jan 26 23:08:34 volumio volumio[21773]: info: CorePlayQueue::getTrack 0 Jan 26 23:08:34 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 23:08:34 volumio volumio[21773]: info: CoreCommandRouter::volumioPushState Jan 26 23:08:34 volumio volumio[21773]: info: CoreStateMachine::setRandom null Jan 26 23:08:34 volumio volumio[21773]: info: CoreStateMachine::pushState Jan 26 23:08:34 volumio volumio[21773]: info: CorePlayQueue::getTrack 0 Jan 26 23:08:34 volumio volumio[21773]: info: CoreCommandRouter::volumioPushState Jan 26 23:08:34 volumio volumio[21773]: info: Setting Device type: Raspberry PI Jan 26 23:08:34 volumio volumio[21773]: info: Completed loading Core Plugins Jan 26 23:08:34 volumio volumio[21773]: info: Preparing to generate the ALSA configuration file Jan 26 23:08:34 volumio volumio[21773]: info: VolumeController:: Volume=100 Mute =false Jan 26 23:08:34 volumio volumio[21773]: info: CoreStateMachine::pushState Jan 26 23:08:34 volumio volumio[21773]: info: CorePlayQueue::getTrack 0 Jan 26 23:08:34 volumio volumio[21773]: info: CoreCommandRouter::volumioPushState Jan 26 23:08:34 volumio volumio[21773]: info: Asound.conf file unchanged, so no further update is needed Jan 26 23:08:34 volumio volumio[21773]: info: Output device has changed, restarting MPD Jan 26 23:08:34 volumio volumio[21773]: info: Output device has changed, restarting Shairport Sync Jan 26 23:08:34 volumio sudo[21947]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 26 23:08:34 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:34 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 23:08:34 volumio sudo[21947]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:08:34 volumio sudo[21949]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 23:08:34 volumio sudo[21949]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:08:34 volumio volumio[21773]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 23:08:34 volumio sudo[21949]: pam_unix(sudo:session): session closed for user root Jan 26 23:08:34 volumio volumio[21773]: info: ___________ START PLUGINS ___________ Jan 26 23:08:34 volumio sudo[21951]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 23:08:34 volumio sudo[21951]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:08:34 volumio sudo[21947]: pam_unix(sudo:session): session closed for user root Jan 26 23:08:34 volumio volumio[21773]: info: ControllerMpd::onStart: Initializing MPD Jan 26 23:08:34 volumio volumio[21773]: info: Creating MPD Configuration file Jan 26 23:08:34 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 23:08:34 volumio volumio[21773]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 23:08:34 volumio sudo[21961]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 23:08:34 volumio volumio[21773]: info: [1769443714725] CoreMusicLibrary::Adding element Media Servers Jan 26 23:08:34 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 23:08:34 volumio sudo[21961]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:08:34 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 26 23:08:34 volumio sudo[21961]: pam_unix(sudo:session): session closed for user root Jan 26 23:08:34 volumio volumio[21773]: info: UPNP Browser: Client initialized successfully Jan 26 23:08:34 volumio sudo[21963]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 23:08:34 volumio sudo[21963]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:08:34 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 26 23:08:34 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 23:08:34 volumio systemd[1]: mpd.service: Consumed 7.423s CPU time. Jan 26 23:08:34 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 26 23:08:34 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 23:08:34 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 23:08:34 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:34 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 23:08:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:34 volumio volumio[21773]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 23:08:34 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:34 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 23:08:34 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 23:08:35 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 23:08:35 volumio volumio[21773]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 23:08:35 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 26 23:08:35 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 23:08:35 volumio volumio[21773]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 23:08:35 volumio volumio[21773]: info: [1769443715090] CoreMusicLibrary::Adding element Last_100 Jan 26 23:08:35 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 26 23:08:35 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 23:08:35 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 23:08:35 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 23:08:35 volumio volumio[21773]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 23:08:35 volumio volumio[21773]: info: [1769443715104] CoreMusicLibrary::Adding element Webradio Jan 26 23:08:35 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 23:08:35 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 23:08:35 volumio volumio[21773]: info: Initializing BBC Radios Jan 26 23:08:35 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 23:08:35 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 23:08:35 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 23:08:35 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 23:08:35 volumio volumio[21773]: info: Creating Spotify config file Jan 26 23:08:35 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:35 volumio sudo[21984]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 26 23:08:35 volumio sudo[21984]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 23:08:35 volumio sudo[21984]: pam_unix(sudo:session): session closed for user root Jan 26 23:08:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Jan 26 23:08:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:08:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:08:35 volumio go-librespot[21992]: go-librespot daemon starting... Jan 26 23:08:36 volumio go-librespot[21993]: time="2026-01-26T23:08:36+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 23:08:36 volumio volumio[21898]: Starting albumart workers Jan 26 23:08:36 volumio volumio[21897]: Starting albumart workers Jan 26 23:08:36 volumio volumio[21773]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 23:08:36 volumio volumio[21773]: info: [1769443716727] CoreMusicLibrary::Adding element YouTube Music Jan 26 23:08:36 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 23:08:36 volumio volumio[21773]: Cannot find translation for source YouTube Music Jan 26 23:08:36 volumio volumio[21773]: info: Volumio Calling Home Jan 26 23:08:36 volumio sudo[22001]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 26 23:08:36 volumio sudo[22001]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:08:36 volumio go-librespot[21993]: time="2026-01-26T23:08:36+07:00" level=info msg="zeroconf server listening on port 43463" Jan 26 23:08:36 volumio volumio[21899]: Starting albumart workers Jan 26 23:08:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:37 volumio sudo[22001]: pam_unix(sudo:session): session closed for user root Jan 26 23:08:37 volumio volumio[21773]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 26 23:08:37 volumio volumio[21773]: info: Discovery: Found device Volumio Jan 26 23:08:37 volumio volumio[21773]: info: CoreCommandRouter::volumioGetState Jan 26 23:08:37 volumio volumio[21773]: info: CorePlayQueue::getTrack 0 Jan 26 23:08:37 volumio volumio[21773]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 26 23:08:37 volumio volumio[21773]: info: Discovery: Found device Volumio Jan 26 23:08:37 volumio volumio[21773]: info: CoreCommandRouter::volumioGetState Jan 26 23:08:37 volumio volumio[21773]: info: CorePlayQueue::getTrack 0 Jan 26 23:08:37 volumio volumio[21773]: info: MPD Permissions set Jan 26 23:08:37 volumio volumio[21773]: info: MPD Permissions set Jan 26 23:08:37 volumio volumio[21773]: info: Upmpdcli Daemon Started Jan 26 23:08:37 volumio volumio[21773]: info: Volumio called home Jan 26 23:08:37 volumio volumio[21773]: info: Spotify config file written Jan 26 23:08:37 volumio sudo[22008]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 26 23:08:37 volumio sudo[22008]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:08:38 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 26 23:08:38 volumio systemd[1]: go-librespot-daemon.service: Killing process 21999 (go-librespot) with signal SIGKILL. Jan 26 23:08:38 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 26 23:08:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:08:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:08:38 volumio go-librespot[22010]: go-librespot daemon starting... Jan 26 23:08:38 volumio sudo[22008]: pam_unix(sudo:session): session closed for user root Jan 26 23:08:38 volumio go-librespot[22017]: time="2026-01-26T23:08:38+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 23:08:38 volumio go-librespot[22017]: time="2026-01-26T23:08:38+07:00" level=debug msg="app state loaded" Jan 26 23:08:38 volumio go-librespot[22017]: time="2026-01-26T23:08:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 23:08:38 volumio volumio[21773]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 26 23:08:38 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:38 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:38 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:38 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:38 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:38 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:38 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:38 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:38 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 23:08:38 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:38 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:38 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:38 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:38 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:38 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:38 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:38 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:38 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:38 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 23:08:38 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:08:38 volumio volumio[21773]: info: No need to fix Spotify hosts Jan 26 23:08:38 volumio go-librespot[22017]: time="2026-01-26T23:08: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 23:08:38 volumio go-librespot[22017]: time="2026-01-26T23:08:38+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]" Jan 26 23:08:38 volumio go-librespot[22017]: time="2026-01-26T23:08:38+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]" Jan 26 23:08:39 volumio go-librespot[22017]: time="2026-01-26T23:08:39+07:00" level=info msg="zeroconf server listening on port 37101" Jan 26 23:08:39 volumio go-librespot[22017]: time="2026-01-26T23:08:39+07:00" level=debug msg="obtained new client token: AABmWBTVJuA1jUCvvhQG1LlNifMZyA2g+NXgG9deNycicMsLBbl+GPhN3EsozuS6xx3B+oxJY0xmorcnvf6P12iVCwip2ZW2/NUkfTg/8q5U3O/7KVwrDHkcsEhefk0iVtWo6KIMDHKKkDr1/5CdCHZBf3U3lvt1CRdHun7VojGF9+ADZrD9z6wnEsp5+buPhkFlEXz6cLh6lmUg+iSkXvFw7+6Wz7/vixEtGnpnkOsGiUR4/MYk5oCj" Jan 26 23:08:39 volumio go-librespot[22017]: time="2026-01-26T23:08:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 23:08:39 volumio go-librespot[22017]: time="2026-01-26T23:08:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 23:08:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 23:08:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 23:08:39 volumio volumio[21773]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 23:08:39 volumio volumio[21773]: SPOTIFY: BQAnbHWdTqEIZIdqHxcx6VRI6tL8QDz4kC_QCbUERAIMXj5CtzHyiBPfRefFEUcljf0tux9kmwQS9HJGXr-fBrtj7OlV6hqRRXasO9lM-oVB9vegFh5HVoF0v4M5XEa94TXfimzRIuA3y1ktYpL9NAy4XyA58ZdjPOw2lr2zxrxD88NdOUCI4ni93E-KGtVQqjZ9cG-lste4btem5iXbGjcsnFxLJSImBP9fA-za-x0k6ax3vSnppANJIPstRSIwnAgc_GMImCVwH7HcokN5aJ1uJoCjv4vjLNFXYJQJDE2jVnAc0wvqphPq Jan 26 23:08:39 volumio volumio[21773]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 23:08:39 volumio volumio[21773]: info: New Spotify access token = BQAnbHWdTqEIZIdqHxcx6VRI6tL8QDz4kC_QCbUERAIMXj5CtzHyiBPfRefFEUcljf0tux9kmwQS9HJGXr-fBrtj7OlV6hqRRXasO9lM-oVB9vegFh5HVoF0v4M5XEa94TXfimzRIuA3y1ktYpL9NAy4XyA58ZdjPOw2lr2zxrxD88NdOUCI4ni93E-KGtVQqjZ9cG-lste4btem5iXbGjcsnFxLJSImBP9fA-za-x0k6ax3vSnppANJIPstRSIwnAgc_GMImCVwH7HcokN5aJ1uJoCjv4vjLNFXYJQJDE2jVnAc0wvqphPq Jan 26 23:08:39 volumio volumio[21773]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 26 23:08:39 volumio volumio[21773]: info: Starting Shairport Sync Jan 26 23:08:39 volumio volumio[21773]: info: Starting Shairport Sync Jan 26 23:08:39 volumio volumio[21773]: info: Starting Shairport Sync Jan 26 23:08:39 volumio sudo[22049]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 23:08:39 volumio sudo[22049]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:08:39 volumio sudo[22051]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 23:08:39 volumio sudo[22051]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:08:39 volumio sudo[22053]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 23:08:39 volumio sudo[22053]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:08:39 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 26 23:08:39 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 26 23:08:39 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 23:08:39 volumio systemd[1]: shairport-sync.service: Consumed 2.427s CPU time. Jan 26 23:08:39 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 23:08:39 volumio sudo[22049]: pam_unix(sudo:session): session closed for user root Jan 26 23:08:40 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 26 23:08:40 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 26 23:08:40 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 23:08:40 volumio volumio[21773]: info: Shairport-Sync Started Jan 26 23:08:40 volumio volumio[21773]: Error adding Membership: Error: addMembership EINVAL Jan 26 23:08:40 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 23:08:40 volumio sudo[22051]: pam_unix(sudo:session): session closed for user root Jan 26 23:08:40 volumio sudo[22053]: pam_unix(sudo:session): session closed for user root Jan 26 23:08:40 volumio volumio[21773]: info: Shairport-Sync Started Jan 26 23:08:40 volumio volumio[21773]: info: Shairport-Sync Started Jan 26 23:08:40 volumio volumio[21773]: info: CoreCommandRouter::volumioGetState Jan 26 23:08:40 volumio volumio[21773]: info: CorePlayQueue::getTrack 0 Jan 26 23:08:40 volumio volumio[21773]: 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"} Jan 26 23:08:40 volumio volumio[21773]: info: Spotify Successfully logged in Jan 26 23:08:40 volumio volumio[21773]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 23:08:40 volumio volumio[21773]: info: [1769443720521] CoreMusicLibrary::Adding element Spotify Jan 26 23:08:40 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 23:08:40 volumio volumio[21773]: Cannot find translation for source YouTube Music Jan 26 23:08:40 volumio volumio[21773]: Cannot find translation for source Spotify Jan 26 23:08:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:41 volumio volumio[21773]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 26 23:08:41 volumio volumio[21773]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 23:08:41 volumio volumio[21773]: info: VolumeController:: Volume=100 Mute =false Jan 26 23:08:41 volumio volumio[21773]: info: CoreCommandRouter::volumioGetState Jan 26 23:08:41 volumio volumio[21773]: info: CorePlayQueue::getTrack 0 Jan 26 23:08:41 volumio volumio[21773]: info: CoreStateMachine::pushState Jan 26 23:08:41 volumio volumio[21773]: info: CorePlayQueue::getTrack 0 Jan 26 23:08:41 volumio volumio[21773]: info: CoreCommandRouter::volumioPushState Jan 26 23:08:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 26 23:08:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:08:42 volumio volumio[21773]: info: go-librespot daemon successfully initialized Jan 26 23:08:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:08:42 volumio go-librespot[22096]: go-librespot daemon starting... Jan 26 23:08:42 volumio go-librespot[22097]: time="2026-01-26T23:08:42+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 23:08:42 volumio go-librespot[22097]: time="2026-01-26T23:08:42+07:00" level=debug msg="app state loaded" Jan 26 23:08:42 volumio go-librespot[22097]: time="2026-01-26T23:08:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 23:08:42 volumio mpd[21991]: 2026-01-26T23:08:42 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 26 23:08:42 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 26 23:08:42 volumio sudo[21951]: pam_unix(sudo:session): session closed for user root Jan 26 23:08:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:42 volumio sudo[21963]: pam_unix(sudo:session): session closed for user root Jan 26 23:08:43 volumio volumio[21773]: error: MPD error: The expression evaluated to a falsy value: Jan 26 23:08:43 volumio volumio[21773]: assert.ok(self.idling) Jan 26 23:08:43 volumio volumio[21773]: error: The expression evaluated to a falsy value: Jan 26 23:08:43 volumio volumio[21773]: assert.ok(self.idling) Jan 26 23:08:43 volumio volumio[21773]: info: MPD running with PID21991 Jan 26 23:08:43 volumio volumio[21773]: ,establishing connection Jan 26 23:08:43 volumio volumio[21773]: error: updateQueue error: null Jan 26 23:08:43 volumio go-librespot[22097]: time="2026-01-26T23:08: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 26 23:08:43 volumio go-librespot[22097]: time="2026-01-26T23:08:43+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]" Jan 26 23:08:43 volumio go-librespot[22097]: time="2026-01-26T23:08:43+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]" Jan 26 23:08:43 volumio go-librespot[22097]: time="2026-01-26T23:08:43+07:00" level=info msg="zeroconf server listening on port 38905" Jan 26 23:08:43 volumio volumio[21773]: info: Completed starting Core Plugins Jan 26 23:08:43 volumio volumio[21773]: info: ------------------------------------------- Jan 26 23:08:43 volumio volumio[21773]: info: ----- MyVolumio plugins startup ---- Jan 26 23:08:43 volumio volumio[21773]: info: ------------------------------------------- Jan 26 23:08:43 volumio volumio[21773]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 26 23:08:43 volumio volumio[21773]: error: updateQueue error: null Jan 26 23:08:43 volumio go-librespot[22097]: time="2026-01-26T23:08:43+07:00" level=debug msg="obtained new client token: AADry0LLBcYkZr339r6bcUvBpP91Zk+UJLhIsU5M1cTUZIvF9E3beM/J113Kx8ZUUJ0eNyagnSaIRl28b8UwleyUlCF5CxPjz4Dcf92tWqaoBdfVdVzLwDKfGBxi7Ip07BRJ8oQpy4Iz2VVZeBg1HrdfkM8SFdIxyAOrUWRl8vcM3nBvbT6BN3ypuy+tkTwAEX29YT2tlgqScLEFYiZfAymLDjJis+7Bo+mKD32A6xuFEFDF9q6Y7cR2hf8=" Jan 26 23:08:43 volumio go-librespot[22097]: time="2026-01-26T23:08:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 23:08:43 volumio go-librespot[22097]: time="2026-01-26T23:08:43+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 23:08:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 23:08:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 23:08:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:45 volumio volumio[21773]: info: Initializing connection to go-librespot Websocket Jan 26 23:08:45 volumio volumio[21773]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 23:08:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 26 23:08:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:08:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:08:47 volumio go-librespot[22108]: go-librespot daemon starting... Jan 26 23:08:47 volumio go-librespot[22109]: time="2026-01-26T23:08:47+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 23:08:47 volumio go-librespot[22109]: time="2026-01-26T23:08:47+07:00" level=debug msg="app state loaded" Jan 26 23:08:47 volumio go-librespot[22109]: time="2026-01-26T23:08:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 23:08:47 volumio go-librespot[22109]: time="2026-01-26T23:08: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 23:08:47 volumio go-librespot[22109]: time="2026-01-26T23:08:47+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]" Jan 26 23:08:47 volumio go-librespot[22109]: time="2026-01-26T23:08:47+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]" Jan 26 23:08:47 volumio go-librespot[22109]: time="2026-01-26T23:08:47+07:00" level=info msg="zeroconf server listening on port 37275" Jan 26 23:08:47 volumio go-librespot[22109]: time="2026-01-26T23:08:47+07:00" level=debug msg="obtained new client token: AADQEnftpb3ysAMb8Zd7RlaPkUXKsF0WfKJv1mI82X4nDpwIa6byqgfI/7XcMvJFBy8pFLcKw9amkLeOd8lDbEdHMBkdhA2lQLFv3bx3veSYPGVBGaYVtt95kkxVcLB1UCIIyj2aSehFtK8QHK+pvFeBKG0k69dSMhop0ovkwxu7ohJyIWjL86/U3lQE0Hd6F4sjMxoBqt6Wc4xSTfqMFfnClp+CbUs9xMbAnq3Nvk7463ZhvGHXRk4V280=" Jan 26 23:08:48 volumio go-librespot[22109]: time="2026-01-26T23:08:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 23:08:48 volumio volumio[21773]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 26 23:08:48 volumio go-librespot[22109]: time="2026-01-26T23:08:48+07:00" level=debug msg="completed keyexchange" Jan 26 23:08:48 volumio go-librespot[22109]: time="2026-01-26T23:08:48+07:00" level=debug msg="completed challenge" Jan 26 23:08:48 volumio go-librespot[22109]: time="2026-01-26T23:08: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 " Jan 26 23:08:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 23:08:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 23:08:48 volumio volumio[21773]: info: Initializing connection to go-librespot Websocket Jan 26 23:08:48 volumio volumio[21773]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 23:08:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 26 23:08:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:08:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:08:51 volumio go-librespot[22117]: go-librespot daemon starting... Jan 26 23:08:51 volumio go-librespot[22118]: time="2026-01-26T23:08:51+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 23:08:51 volumio go-librespot[22118]: time="2026-01-26T23:08:51+07:00" level=debug msg="app state loaded" Jan 26 23:08:51 volumio go-librespot[22118]: time="2026-01-26T23:08:51+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 23:08:51 volumio volumio[21773]: info: Initializing connection to go-librespot Websocket Jan 26 23:08:51 volumio go-librespot[22118]: time="2026-01-26T23:08:51+07:00" level=debug msg="new websocket client" Jan 26 23:08:51 volumio volumio[21773]: info: Connection to go-librespot Websocket established Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 26 23:08:52 volumio volumio[21773]: info: Adding plugin bluetooth to MyMusic Plugins Jan 26 23:08:52 volumio volumio[21773]: info: Adding plugin multiroom to MyMusic Plugins Jan 26 23:08:52 volumio volumio[21773]: info: Adding plugin metavolumio to MyMusic Plugins Jan 26 23:08:52 volumio volumio[21773]: info: Adding plugin cd_controller to MyMusic Plugins Jan 26 23:08:52 volumio volumio[21773]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 26 23:08:52 volumio volumio[21773]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 26 23:08:52 volumio volumio[21773]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 26 23:08:52 volumio volumio[21773]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 26 23:08:52 volumio go-librespot[22118]: time="2026-01-26T23:08: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]" Jan 26 23:08:52 volumio go-librespot[22118]: time="2026-01-26T23:08: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]" Jan 26 23:08:52 volumio go-librespot[22118]: time="2026-01-26T23:08: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]" Jan 26 23:08:52 volumio go-librespot[22118]: time="2026-01-26T23:08:52+07:00" level=info msg="zeroconf server listening on port 36591" Jan 26 23:08:52 volumio go-librespot[22118]: time="2026-01-26T23:08:52+07:00" level=debug msg="obtained new client token: AAAIrxzeL4u52o7Ikn0yLDRtG8b72B+xPymhpBKXi5G694UxW18tI07bULMwKItlygE5H3LRQgo4uutH79rLOpz8W0tsuy0MARIlC4xHooEM7h0totbHWhAJmwGSWFLPHepQu9e6iZu45WbVHld4LOxya5t+UovgkIUow6yf1hLCWSjLZ154VSWSm+/Ed5faIA0Iqr6uNd1ISkP5SauSQHkguq1RqW9UewFx1GBstizPRDKoKEV6JOh2nGM=" Jan 26 23:08:52 volumio go-librespot[22118]: time="2026-01-26T23:08:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 23:08:52 volumio go-librespot[22118]: time="2026-01-26T23:08:52+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 23:08:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 23:08:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 23:08:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:53 volumio volumio[21773]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 26 23:08:53 volumio volumio[21773]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 26 23:08:53 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 23:08:53 volumio volumio[21773]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 23:08:53 volumio volumio[21773]: info: Starting MyVolumio Remote Streaming Endpoints Jan 26 23:08:53 volumio volumio[21773]: info: MyVolumio login type: Token Jan 26 23:08:54 volumio volumio[21773]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 26 23:08:54 volumio volumio[21773]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 26 23:08:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 26 23:08:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:08:55 volumio volumio[21773]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 26 23:08:55 volumio volumio[21773]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 26 23:08:55 volumio volumio[21773]: info: Streaming services startup Jan 26 23:08:55 volumio volumio[21773]: info: Starting Streaming Daemon Jan 26 23:08:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:08:55 volumio volumio[21773]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 26 23:08:55 volumio go-librespot[22141]: go-librespot daemon starting... Jan 26 23:08:55 volumio sudo[22143]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 26 23:08:55 volumio sudo[22143]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:08:55 volumio go-librespot[22148]: time="2026-01-26T23:08:55+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 23:08:55 volumio go-librespot[22148]: time="2026-01-26T23:08:55+07:00" level=debug msg="app state loaded" Jan 26 23:08:55 volumio go-librespot[22148]: time="2026-01-26T23:08:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 23:08:55 volumio sudo[22143]: pam_unix(sudo:session): session closed for user root Jan 26 23:08:56 volumio volumio[21773]: info: Getting Spotify volume Jan 26 23:08:56 volumio volumio[21773]: info: Connection to go-librespot Websocket closed Jan 26 23:08:56 volumio volumio[21773]: error: Cannot start Volumio Streaming Daemon Jan 26 23:08:56 volumio volumio[21773]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 26 23:08:56 volumio volumio[21773]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 26 23:08:56 volumio volumio[21773]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 26 23:08:56 volumio go-librespot[22148]: time="2026-01-26T23:08: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]" Jan 26 23:08:56 volumio go-librespot[22148]: time="2026-01-26T23:08: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]" Jan 26 23:08:56 volumio go-librespot[22148]: time="2026-01-26T23:08: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]" Jan 26 23:08:56 volumio volumio[21773]: info: CoreCommandRouter::volumioGetState Jan 26 23:08:56 volumio volumio[21773]: info: CorePlayQueue::getTrack 0 Jan 26 23:08:56 volumio go-librespot[22148]: time="2026-01-26T23:08:56+07:00" level=info msg="zeroconf server listening on port 33897" Jan 26 23:08:56 volumio volumio[21773]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 26 23:08:56 volumio volumio[21773]: SPOTIFY: SPOTIFY VOLUME undefined Jan 26 23:08:56 volumio volumio[21773]: SPOTIFY: VOLUMIO VOLUME 100 Jan 26 23:08:56 volumio volumio[21773]: info: Aligning Spotify Volume to Volumio Volume Jan 26 23:08:56 volumio volumio[21773]: info: CoreCommandRouter::volumioGetState Jan 26 23:08:56 volumio volumio[21773]: info: CorePlayQueue::getTrack 0 Jan 26 23:08:56 volumio volumio[21773]: info: Setting Spotify Volume from Volumio: 100 Jan 26 23:08:56 volumio go-librespot[22148]: time="2026-01-26T23:08:56+07:00" level=debug msg="obtained new client token: AABs/1/AaAsfxBATiItUtqAuPjpvY3XWDZ8rSb5RFwiwCyEKX4cX/lsePW+PLpNlNJEToo7PR+dqsIR6E9XhcKXIYBiLWXnAHxX+GUaY3dWUZMccewvFB2/D95yY0RagIiLlqFHznMvPd5Z5mGt9T3EjMtqRMbHBNMuFMm7ITZ+DMZ5HVtkLPT4Ky30p4Tfgns6NHRb1bSwvBWH3NlX+ekqooJxaQe8YVxmwLpcIWzUtpOOsBKuA6Fgmdls=" Jan 26 23:08:56 volumio go-librespot[22148]: time="2026-01-26T23:08:56+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" Jan 26 23:08:56 volumio go-librespot[22148]: time="2026-01-26T23:08:56+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 26 23:08:56 volumio go-librespot[22148]: time="2026-01-26T23:08:56+07:00" level=debug msg="completed keyexchange" Jan 26 23:08:56 volumio go-librespot[22148]: time="2026-01-26T23:08:56+07:00" level=debug msg="completed challenge" Jan 26 23:08:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:56 volumio go-librespot[22148]: time="2026-01-26T23:08: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 " Jan 26 23:08:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 23:08:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 23:08:57 volumio volumio[21773]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 23:08:57 volumio volumio[21773]: Error: socket hang up Jan 26 23:08:57 volumio volumio[21773]: at connResetException (node:internal/errors:720:14) Jan 26 23:08:57 volumio volumio[21773]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 26 23:08:57 volumio volumio[21773]: at Socket.emit (node:events:526:35) Jan 26 23:08:57 volumio volumio[21773]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 26 23:08:57 volumio volumio[21773]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 26 23:08:57 volumio volumio[21773]: code: 'ECONNRESET', Jan 26 23:08:57 volumio volumio[21773]: response: undefined Jan 26 23:08:57 volumio volumio[21773]: } Jan 26 23:08:57 volumio volumio[21773]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 23:08:58 volumio sudo[22170]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-26 23:07' Jan 26 23:08:58 volumio sudo[22170]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:08:58 volumio sudo[22170]: pam_unix(sudo:session): session closed for user root Jan 26 23:08:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:08:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:08:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:08:59 volumio volumio-remote-updater[628]: [2026-01-26 23:08:59] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Jan 26 23:08:59 volumio volumio-remote-updater[628]: [2026-01-26 23:08:59] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Jan 26 23:08:59 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 26 23:08:59 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 26 23:08:59 volumio systemd[1]: volumio.service: Consumed 1min 10.202s CPU time. Jan 26 23:08:59 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 26 23:08:59 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 26 23:08:59 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 7683. Jan 26 23:08:59 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 26 23:08:59 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 26 23:08:59 volumio systemd[1]: volumio.service: Consumed 1min 10.202s CPU time. Jan 26 23:08:59 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 26 23:08:59 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 26 23:09:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 26 23:09:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:09:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:09:00 volumio go-librespot[22197]: go-librespot daemon starting... Jan 26 23:09:00 volumio go-librespot[22198]: time="2026-01-26T23:09:00+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 23:09:00 volumio go-librespot[22198]: time="2026-01-26T23:09:00+07:00" level=debug msg="app state loaded" Jan 26 23:09:00 volumio go-librespot[22198]: time="2026-01-26T23:09:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 23:09:00 volumio go-librespot[22198]: time="2026-01-26T23:09: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 26 23:09:00 volumio go-librespot[22198]: time="2026-01-26T23:09:00+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]" Jan 26 23:09:00 volumio go-librespot[22198]: time="2026-01-26T23:09:00+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]" Jan 26 23:09:00 volumio go-librespot[22198]: time="2026-01-26T23:09:00+07:00" level=info msg="zeroconf server listening on port 40193" Jan 26 23:09:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:09:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:09:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:09:01 volumio go-librespot[22198]: time="2026-01-26T23:09:01+07:00" level=debug msg="obtained new client token: AADkuRYfbyZW/TBAPy/ks8T4MXF6qhmqufw4t3+oMgL7Rc0cIG2QP11ELyx/iTqCxQ1XEsT6c/hBxBhX8I6gP79LT9MXc+yLbdocCpdGq2Yu1BCrWJCSj6kf1wKb/Xt70hgfQKkrg0KnUPsWPdwKiMrGG2EnXWBmmQ4bv8MvquexrrjUiys/k1sBMdKLM3WSa3/c1qpiq75BNQ2TLt/aq9VBF5DfTDE2Z/mqE04Uo8TZK1+vasVnNk56" Jan 26 23:09:01 volumio go-librespot[22198]: time="2026-01-26T23:09:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 23:09:01 volumio go-librespot[22198]: time="2026-01-26T23:09:01+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 23:09:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 23:09:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 23:09:02 volumio volumio[22182]: info: ------------------------------------------- Jan 26 23:09:02 volumio volumio[22182]: info: ----- Volumio3 ---- Jan 26 23:09:02 volumio volumio[22182]: info: ------------------------------------------- Jan 26 23:09:02 volumio volumio[22182]: info: ----- System startup ---- Jan 26 23:09:02 volumio volumio[22182]: info: ------------------------------------------- Jan 26 23:09:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:09:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:09:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:09:04 volumio volumio-remote-updater[628]: [2026-01-26 23:09:04] [connect] Successful connection Jan 26 23:09:04 volumio volumio[22182]: info: MYVOLUMIO Environment detected Jan 26 23:09:04 volumio volumio[22182]: info: Plugin folders cleanup Jan 26 23:09:04 volumio volumio[22182]: info: Scanning into folder /volumio/app/plugins/ Jan 26 23:09:04 volumio volumio[22182]: info: Scanning category audio_interface Jan 26 23:09:04 volumio volumio[22182]: info: Scanning category miscellanea Jan 26 23:09:04 volumio volumio[22182]: info: Scanning category music_service Jan 26 23:09:04 volumio volumio[22182]: info: Scanning category plugins.json Jan 26 23:09:04 volumio volumio[22182]: info: Scanning category system_controller Jan 26 23:09:04 volumio volumio[22182]: info: Scanning category user_interface Jan 26 23:09:04 volumio volumio[22182]: info: Scanning into folder /data/plugins/ Jan 26 23:09:04 volumio volumio[22182]: info: Scanning category music_service Jan 26 23:09:04 volumio volumio[22182]: info: Plugin folders cleanup completed Jan 26 23:09:04 volumio volumio[22182]: info: ------------------------------------------- Jan 26 23:09:04 volumio volumio[22182]: info: ----- Core plugins startup ---- Jan 26 23:09:04 volumio volumio[22182]: info: ------------------------------------------- Jan 26 23:09:04 volumio volumio[22182]: info: Loading plugins from folder /volumio/app/plugins/ Jan 26 23:09:04 volumio volumio[22182]: info: Adding plugin upnp to MyMusic Plugins Jan 26 23:09:04 volumio volumio[22182]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 26 23:09:04 volumio volumio[22182]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 26 23:09:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 26 23:09:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:09:04 volumio volumio[22182]: info: Loading plugins from folder /data/plugins/ Jan 26 23:09:04 volumio volumio[22182]: info: Loading plugin "system"... Jan 26 23:09:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:09:04 volumio volumio[22182]: info: Loading plugin "appearance"... Jan 26 23:09:04 volumio go-librespot[22215]: go-librespot daemon starting... Jan 26 23:09:04 volumio go-librespot[22219]: time="2026-01-26T23:09:04+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 23:09:04 volumio go-librespot[22219]: time="2026-01-26T23:09:04+07:00" level=debug msg="app state loaded" Jan 26 23:09:04 volumio go-librespot[22219]: time="2026-01-26T23:09:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 23:09:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:09:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:09:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:09:05 volumio go-librespot[22219]: time="2026-01-26T23:09: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 23:09:05 volumio go-librespot[22219]: time="2026-01-26T23:09:05+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]" Jan 26 23:09:05 volumio go-librespot[22219]: time="2026-01-26T23:09:05+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]" Jan 26 23:09:05 volumio go-librespot[22219]: time="2026-01-26T23:09:05+07:00" level=info msg="zeroconf server listening on port 39127" Jan 26 23:09:05 volumio go-librespot[22219]: time="2026-01-26T23:09:05+07:00" level=debug msg="obtained new client token: AABFZOAVg83IqD6jRsNfrGUOeE3Y7ms7OBQ4v0MkIPfZyJviYB7i+0kZ6YpacVBeTAmIlrCoOhhwtSb2pdcrWL1FlSw5vw8EyJQqmwGrErzwedOiSQ8JuMGKaiBH9vfJ1XpqW7I/smuIqSaLKZf65K1VI2hucUZP4j+vevXzR6oqc4qse7dMpOqa4UZuQjhbYRJY+kE3XX4CWan81RjK4+L7aWVDFD0R55RXlWV/VmKYuUTYNcR58gRCBcg=" Jan 26 23:09:05 volumio go-librespot[22219]: time="2026-01-26T23:09:05+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" Jan 26 23:09:05 volumio go-librespot[22219]: time="2026-01-26T23:09:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 26 23:09:05 volumio go-librespot[22219]: time="2026-01-26T23:09:05+07:00" level=debug msg="completed keyexchange" Jan 26 23:09:05 volumio go-librespot[22219]: time="2026-01-26T23:09:05+07:00" level=debug msg="completed challenge" Jan 26 23:09:05 volumio go-librespot[22219]: time="2026-01-26T23:09: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 " Jan 26 23:09:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 23:09:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 23:09:06 volumio volumio[22182]: info: Loading plugin "network"... Jan 26 23:09:06 volumio volumio[22182]: info: Refreshing Cached IP Addresses Jan 26 23:09:06 volumio sudo[22228]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 23:09:06 volumio sudo[22228]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:09:06 volumio sudo[22230]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 23:09:06 volumio sudo[22228]: pam_unix(sudo:session): session closed for user root Jan 26 23:09:06 volumio sudo[22230]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:09:06 volumio sudo[22230]: pam_unix(sudo:session): session closed for user root Jan 26 23:09:06 volumio volumio[22182]: info: Loading plugin "services"... Jan 26 23:09:06 volumio volumio[22182]: info: Loading plugin "alsa_controller"... Jan 26 23:09:06 volumio sudo[22239]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 26 23:09:06 volumio sudo[22239]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:09:06 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 23:09:06 volumio volumio[22182]: info: Loading plugin "wizard"... Jan 26 23:09:06 volumio volumio[22182]: info: Loading plugin "networkfs"... Jan 26 23:09:06 volumio volumio[22182]: info: Starting Udev Watcher for removable devices Jan 26 23:09:06 volumio volumio[22182]: info: Ignoring mount for partition: boot Jan 26 23:09:06 volumio volumio[22182]: info: Ignoring mount for partition: volumio Jan 26 23:09:06 volumio volumio[22182]: info: Ignoring mount for partition: volumio_data Jan 26 23:09:06 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 23:09:06 volumio volumio[22182]: info: Loading plugin "volumio_command_line_client"... Jan 26 23:09:06 volumio volumio[22182]: info: Loading plugin "upnp"... Jan 26 23:09:06 volumio volumio[22182]: info: [1769443746952] Starting Upmpd Daemon Jan 26 23:09:06 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 23:09:06 volumio volumio[22182]: info: Loading plugin "my_music"... Jan 26 23:09:06 volumio volumio[22182]: info: Loading plugin "mpd"... Jan 26 23:09:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:09:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:09:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:09:07 volumio volumio[22182]: info: Loading plugin "upnp_browser"... Jan 26 23:09:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:09:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:09:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:09:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 26 23:09:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:09:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:09:09 volumio go-librespot[22261]: go-librespot daemon starting... Jan 26 23:09:09 volumio go-librespot[22262]: time="2026-01-26T23:09:09+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 23:09:09 volumio go-librespot[22262]: time="2026-01-26T23:09:09+07:00" level=debug msg="app state loaded" Jan 26 23:09:09 volumio go-librespot[22262]: time="2026-01-26T23:09:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 23:09:09 volumio sudo[22239]: pam_unix(sudo:session): session closed for user root Jan 26 23:09:09 volumio go-librespot[22262]: time="2026-01-26T23:09: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 23:09:09 volumio go-librespot[22262]: time="2026-01-26T23:09:09+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]" Jan 26 23:09:09 volumio go-librespot[22262]: time="2026-01-26T23:09:09+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]" Jan 26 23:09:09 volumio go-librespot[22262]: time="2026-01-26T23:09:09+07:00" level=info msg="zeroconf server listening on port 46269" Jan 26 23:09:09 volumio go-librespot[22262]: time="2026-01-26T23:09:09+07:00" level=debug msg="obtained new client token: AABq4L7s8Xu3flxWoJXiM415iy1wS5T3WKsHDBA92k9fD8qMbDx3BmNUR8gwlWlY2WzkZo8kJjet1u9fQN6nMKQzSoXklJpHTd9axh3mjMyhq8iJyLovpEpAqyKIpMTNJCBf1vhUFJMLwMUS5rGnRPYo37RtqSLgtTEN1z9SeVLuZThKv2LYM0SvEdLIVFo2W4yydmYg7HGs9DahqIv+ulMAYdAqORoBFlwD5uXt8M9yvXlx+GnkeiPHL1I=" Jan 26 23:09:10 volumio go-librespot[22262]: time="2026-01-26T23:09: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" Jan 26 23:09:10 volumio go-librespot[22262]: time="2026-01-26T23:09:10+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Jan 26 23:09:10 volumio go-librespot[22262]: time="2026-01-26T23:09:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Jan 26 23:09:10 volumio go-librespot[22262]: time="2026-01-26T23:09:10+07:00" level=debug msg="completed keyexchange" Jan 26 23:09:10 volumio go-librespot[22262]: time="2026-01-26T23:09:10+07:00" level=debug msg="completed challenge" Jan 26 23:09:10 volumio go-librespot[22262]: time="2026-01-26T23:09: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 " Jan 26 23:09:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 23:09:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 23:09:10 volumio volumio[22182]: info: Starting UPNP Browser Jan 26 23:09:10 volumio volumio[22182]: info: Loading plugin "alarm-clock"... Jan 26 23:09:10 volumio volumio[22182]: info: Loading plugin "airplay_emulation"... Jan 26 23:09:10 volumio volumio[22182]: info: Starting Shairport Sync Jan 26 23:09:10 volumio volumio[22182]: info: Loading plugin "last_100"... Jan 26 23:09:10 volumio volumio[22182]: info: Loading plugin "webradio"... Jan 26 23:09:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:09:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:09:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:09:11 volumio volumio[22182]: info: Loading plugin "i2s_dacs"... Jan 26 23:09:11 volumio volumio[22182]: info: Loading plugin "volumiodiscovery"... Jan 26 23:09:11 volumio volumio[22182]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 23:09:11 volumio volumio[22182]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 23:09:11 volumio volumio[22182]: *** WARNING *** For more information see Jan 26 23:09:11 volumio volumio[22182]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 23:09:11 volumio volumio[22182]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 23:09:11 volumio volumio[22182]: *** WARNING *** For more information see Jan 26 23:09:11 volumio node[22182]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 23:09:11 volumio node[22182]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 23:09:11 volumio node[22182]: *** WARNING *** For more information see Jan 26 23:09:11 volumio node[22182]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 23:09:11 volumio node[22182]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 23:09:11 volumio node[22182]: *** WARNING *** For more information see Jan 26 23:09:11 volumio volumio[22182]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 26 23:09:11 volumio volumio[22182]: info: Discovery: Started advertising with name: Volumio Jan 26 23:09:11 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 23:09:11 volumio volumio[22182]: info: Loading plugin "spop"... Jan 26 23:09:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:09:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:09:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:09:13 volumio volumio[22182]: info: Loading plugin "ytcr"... Jan 26 23:09:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 26 23:09:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:09:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:09:13 volumio go-librespot[22276]: go-librespot daemon starting... Jan 26 23:09:13 volumio go-librespot[22277]: time="2026-01-26T23:09:13+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 23:09:13 volumio go-librespot[22277]: time="2026-01-26T23:09:13+07:00" level=debug msg="app state loaded" Jan 26 23:09:13 volumio go-librespot[22277]: time="2026-01-26T23:09:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 23:09:14 volumio go-librespot[22277]: time="2026-01-26T23:09: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-gew4.spotify.com:80]" Jan 26 23:09:14 volumio go-librespot[22277]: time="2026-01-26T23:09:14+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]" Jan 26 23:09:14 volumio go-librespot[22277]: time="2026-01-26T23:09:14+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]" Jan 26 23:09:14 volumio go-librespot[22277]: time="2026-01-26T23:09:14+07:00" level=info msg="zeroconf server listening on port 44143" Jan 26 23:09:14 volumio go-librespot[22277]: time="2026-01-26T23:09:14+07:00" level=debug msg="obtained new client token: AAD1Vl0WXuHhJmKCO/YmOd+mDJmm51UkPYIHXd0Zx5A0TtHoHdN1KvMob/bWWoknObQ7a0LLc3uEUYqiiQk+8bGDlL9vNcU0Zd6QaaP9BzEelLbsY/ExZdtmwZ9/3fPLE2vWPuqX+aVJXlDitRkguJbCMU4Je9jnHXvodOxHDoPO5UAjVuGUzxy0wGnLekXU3j9iKl0yCh9wab2uFTI3k9m1YQqYbvi4O8vjOYhHt7Tj/RoTF9U4rHu/VPQ=" Jan 26 23:09:14 volumio go-librespot[22277]: time="2026-01-26T23:09:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 23:09:14 volumio go-librespot[22277]: time="2026-01-26T23:09:14+07:00" level=debug msg="completed keyexchange" Jan 26 23:09:14 volumio go-librespot[22277]: time="2026-01-26T23:09:14+07:00" level=debug msg="completed challenge" Jan 26 23:09:14 volumio go-librespot[22277]: time="2026-01-26T23:09: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 " Jan 26 23:09:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 23:09:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 23:09:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:09:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:09:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:09:15 volumio volumio[22182]: info: Loading plugin "ytmusic"... Jan 26 23:09:16 volumio volumio-remote-updater[628]: [2026-01-26 23:09:16] [connect] Successful connection Jan 26 23:09:16 volumio volumio[22182]: info: Loading plugin "outputs"... Jan 26 23:09:16 volumio volumio[22182]: info: Loading plugin "albumart"... Jan 26 23:09:16 volumio volumio[22182]: info: Plugin example_plugin is not enabled Jan 26 23:09:16 volumio volumio[22182]: info: Loading plugin "inputs"... Jan 26 23:09:16 volumio volumio[22182]: info: Loading plugin "updater_comm"... Jan 26 23:09:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:09:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:09:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:09:17 volumio volumio[22182]: info: Plugin mpdemulation is not enabled Jan 26 23:09:17 volumio volumio[22182]: info: Loading plugin "rest_api"... Jan 26 23:09:17 volumio volumio[22182]: info: Loading plugin "websocket"... Jan 26 23:09:17 volumio volumio[22182]: info: Starting Socket.io Server version 1.7.4 Jan 26 23:09:17 volumio volumio[22182]: info: Loading plugin "RoonBridge"... Jan 26 23:09:17 volumio volumio[22182]: info: Applying required configuration parameters for plugin RoonBridge Jan 26 23:09:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 26 23:09:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:09:17 volumio volumio[22182]: info: Loading i18n strings for locale en Jan 26 23:09:17 volumio volumio[22182]: Updating browse sources language Jan 26 23:09:17 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 23:09:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:09:17 volumio go-librespot[22308]: go-librespot daemon starting... Jan 26 23:09:17 volumio go-librespot[22309]: time="2026-01-26T23:09:17+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 23:09:17 volumio go-librespot[22309]: time="2026-01-26T23:09:17+07:00" level=debug msg="app state loaded" Jan 26 23:09:17 volumio go-librespot[22309]: time="2026-01-26T23:09:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 23:09:18 volumio volumio[22298]: Forking 3 albumart workers Jan 26 23:09:18 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 23:09:18 volumio volumio[22182]: info: CoreCommandRouter::initPlayerControls Jan 26 23:09:18 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:18 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:18 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:18 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:18 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:18 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:18 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:18 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:18 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 23:09:18 volumio volumio[22182]: Express server listening on port 3000 Jan 26 23:09:18 volumio volumio[22182]: [Metrics] WebUI: 16s 88.94ms Jan 26 23:09:18 volumio volumio[22182]: info: CoreStateMachine::resetVolumioState Jan 26 23:09:18 volumio volumio[22182]: info: CoreStateMachine::getcurrentVolume Jan 26 23:09:18 volumio volumio[22182]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 23:09:18 volumio sudo[22349]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 23:09:18 volumio sudo[22349]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:09:18 volumio sudo[22349]: pam_unix(sudo:session): session closed for user root Jan 26 23:09:18 volumio sudo[22351]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 23:09:18 volumio sudo[22351]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:09:18 volumio sudo[22351]: pam_unix(sudo:session): session closed for user root Jan 26 23:09:18 volumio volumio[22182]: info: Volumio Network Manager: Network status updated: 1 Jan 26 23:09:18 volumio go-librespot[22309]: time="2026-01-26T23:09: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 23:09:18 volumio go-librespot[22309]: time="2026-01-26T23:09:18+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]" Jan 26 23:09:18 volumio go-librespot[22309]: time="2026-01-26T23:09:18+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]" Jan 26 23:09:18 volumio go-librespot[22309]: time="2026-01-26T23:09:18+07:00" level=info msg="zeroconf server listening on port 39765" Jan 26 23:09:18 volumio go-librespot[22309]: time="2026-01-26T23:09:18+07:00" level=debug msg="obtained new client token: AAB5hmrbnVxZSk9AVDMviXHeLKCEWnTAJc1vA7EaJlw7qOKPppjTuvVrefbVYv8/TMlDk6CKQBmWA1pwc7dww2et3iunORimUgTZcvI7CHfDFFg3Dur/H2YsaT7l3OoO/EsoHWEgZqyAGBz+4drAvi+qZivzZIF8kUrVRUWjRCP5EnyW0vH6DZtownOAVAIe9OBWsjHwfcYofl1tNLd8gEezv7wmvhuNCZ94PjzGgOi7kdYSjGF8J7WO1Ac=" Jan 26 23:09:18 volumio volumio[22182]: info: VolumeController:: Volume=100 Mute =false Jan 26 23:09:18 volumio volumio[22182]: info: CoreStateMachine::pushState Jan 26 23:09:18 volumio volumio[22182]: info: CorePlayQueue::getTrack 0 Jan 26 23:09:18 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 23:09:18 volumio volumio[22182]: info: CoreCommandRouter::volumioPushState Jan 26 23:09:18 volumio go-librespot[22309]: time="2026-01-26T23:09:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 23:09:18 volumio volumio[22182]: info: CoreStateMachine::updateTrackBlock Jan 26 23:09:18 volumio volumio[22182]: info: CorePlayQueue::getTrackBlock Jan 26 23:09:18 volumio volumio[22182]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 23:09:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:09:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:09:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:09:18 volumio volumio-remote-updater[628]: [2026-01-26 23:09:18] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769443756 101 Jan 26 23:09:19 volumio volumio[22182]: 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 Jan 26 23:09:19 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 23:09:19 volumio go-librespot[22309]: time="2026-01-26T23:09:19+07:00" level=debug msg="completed keyexchange" Jan 26 23:09:19 volumio volumio[22182]: info: Reloading queue from file Jan 26 23:09:19 volumio go-librespot[22309]: time="2026-01-26T23:09:19+07:00" level=debug msg="completed challenge" Jan 26 23:09:19 volumio volumio[22182]: info: CoreStateMachine::setRepeat null single undefined Jan 26 23:09:19 volumio volumio[22182]: info: CoreStateMachine::pushState Jan 26 23:09:19 volumio volumio[22182]: info: CorePlayQueue::getTrack 0 Jan 26 23:09:19 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 23:09:19 volumio go-librespot[22309]: time="2026-01-26T23:09: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 " Jan 26 23:09:19 volumio volumio[22182]: info: CoreCommandRouter::volumioPushState Jan 26 23:09:19 volumio volumio[22182]: info: CoreStateMachine::setRandom null Jan 26 23:09:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 23:09:19 volumio volumio[22182]: info: CoreStateMachine::pushState Jan 26 23:09:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 23:09:19 volumio volumio[22182]: info: CorePlayQueue::getTrack 0 Jan 26 23:09:19 volumio volumio[22182]: info: CoreCommandRouter::volumioPushState Jan 26 23:09:19 volumio volumio[22182]: info: Setting Device type: Raspberry PI Jan 26 23:09:19 volumio volumio[22182]: info: Completed loading Core Plugins Jan 26 23:09:19 volumio volumio[22182]: info: Preparing to generate the ALSA configuration file Jan 26 23:09:19 volumio volumio[22182]: info: VolumeController:: Volume=100 Mute =false Jan 26 23:09:19 volumio volumio[22182]: info: CoreStateMachine::pushState Jan 26 23:09:19 volumio volumio[22182]: info: CorePlayQueue::getTrack 0 Jan 26 23:09:19 volumio volumio[22182]: info: CoreCommandRouter::volumioPushState Jan 26 23:09:19 volumio volumio[22182]: info: Asound.conf file unchanged, so no further update is needed Jan 26 23:09:19 volumio volumio[22182]: info: Output device has changed, restarting MPD Jan 26 23:09:19 volumio sudo[22368]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 26 23:09:19 volumio sudo[22368]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:09:19 volumio volumio[22182]: info: Output device has changed, restarting Shairport Sync Jan 26 23:09:19 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:19 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 23:09:19 volumio sudo[22370]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 23:09:19 volumio sudo[22370]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:09:19 volumio sudo[22370]: pam_unix(sudo:session): session closed for user root Jan 26 23:09:19 volumio sudo[22373]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 23:09:19 volumio sudo[22373]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:09:19 volumio sudo[22368]: pam_unix(sudo:session): session closed for user root Jan 26 23:09:19 volumio volumio[22182]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 23:09:19 volumio volumio[22182]: info: ___________ START PLUGINS ___________ Jan 26 23:09:19 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 26 23:09:19 volumio volumio[22182]: info: ControllerMpd::onStart: Initializing MPD Jan 26 23:09:19 volumio volumio[22182]: info: Creating MPD Configuration file Jan 26 23:09:19 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 26 23:09:19 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 23:09:19 volumio systemd[1]: mpd.service: Consumed 7.410s CPU time. Jan 26 23:09:19 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 23:09:19 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 26 23:09:19 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 23:09:19 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 23:09:19 volumio volumio[22182]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 23:09:19 volumio volumio[22182]: info: [1769443759854] CoreMusicLibrary::Adding element Media Servers Jan 26 23:09:19 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 23:09:19 volumio volumio[22182]: info: UPNP Browser: Client initialized successfully Jan 26 23:09:19 volumio sudo[22383]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 23:09:19 volumio sudo[22383]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:09:19 volumio sudo[22381]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 23:09:19 volumio sudo[22381]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:09:19 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:19 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 23:09:19 volumio sudo[22381]: pam_unix(sudo:session): session closed for user root Jan 26 23:09:19 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 23:09:19 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 23:09:20 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 26 23:09:20 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 23:09:20 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 26 23:09:20 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 23:09:20 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 23:09:20 volumio volumio[22182]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 23:09:20 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:20 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 23:09:20 volumio volumio[22182]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 23:09:20 volumio volumio[22182]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 23:09:20 volumio volumio[22182]: info: [1769443760131] CoreMusicLibrary::Adding element Last_100 Jan 26 23:09:20 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 23:09:20 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 23:09:20 volumio volumio[22182]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 23:09:20 volumio volumio[22182]: info: [1769443760155] CoreMusicLibrary::Adding element Webradio Jan 26 23:09:20 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 23:09:20 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 23:09:20 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 23:09:20 volumio volumio[22182]: info: Initializing BBC Radios Jan 26 23:09:20 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 23:09:20 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 23:09:20 volumio volumio[22182]: info: Creating Spotify config file Jan 26 23:09:20 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:20 volumio sudo[22398]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 26 23:09:20 volumio sudo[22398]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 23:09:20 volumio sudo[22398]: pam_unix(sudo:session): session closed for user root Jan 26 23:09:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:09:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:09:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:09:21 volumio volumio[22316]: Starting albumart workers Jan 26 23:09:21 volumio volumio[22315]: Starting albumart workers Jan 26 23:09:21 volumio volumio[22182]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 23:09:21 volumio volumio[22182]: info: [1769443761532] CoreMusicLibrary::Adding element YouTube Music Jan 26 23:09:21 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 23:09:21 volumio volumio[22182]: Cannot find translation for source YouTube Music Jan 26 23:09:21 volumio volumio[22182]: info: Volumio Calling Home Jan 26 23:09:21 volumio volumio[22317]: Starting albumart workers Jan 26 23:09:21 volumio sudo[22415]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 26 23:09:21 volumio sudo[22415]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:09:21 volumio sudo[22415]: pam_unix(sudo:session): session closed for user root Jan 26 23:09:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 26 23:09:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:09:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:09:22 volumio go-librespot[22420]: go-librespot daemon starting... Jan 26 23:09:22 volumio go-librespot[22421]: time="2026-01-26T23:09:22+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 23:09:22 volumio volumio[22182]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 26 23:09:22 volumio volumio[22182]: info: Discovery: Found device Volumio Jan 26 23:09:22 volumio volumio[22182]: info: CoreCommandRouter::volumioGetState Jan 26 23:09:22 volumio volumio[22182]: info: CorePlayQueue::getTrack 0 Jan 26 23:09:22 volumio volumio[22182]: info: MPD Permissions set Jan 26 23:09:22 volumio volumio[22182]: info: MPD Permissions set Jan 26 23:09:22 volumio volumio[22182]: info: Upmpdcli Daemon Started Jan 26 23:09:22 volumio volumio[22182]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 26 23:09:22 volumio volumio[22182]: info: Discovery: Found device Volumio Jan 26 23:09:22 volumio volumio[22182]: info: CoreCommandRouter::volumioGetState Jan 26 23:09:22 volumio volumio[22182]: info: CorePlayQueue::getTrack 0 Jan 26 23:09:22 volumio volumio[22182]: info: Spotify config file written Jan 26 23:09:22 volumio sudo[22429]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 26 23:09:22 volumio volumio[22182]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 26 23:09:22 volumio volumio[22182]: info: Volumio called home Jan 26 23:09:22 volumio sudo[22429]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:09:22 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:22 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:22 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:22 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:22 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:22 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:22 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:22 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:22 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 23:09:22 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:22 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:22 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:22 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:22 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:22 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:22 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:22 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:22 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:09:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:09:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:09:23 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 26 23:09:23 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 26 23:09:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:09:23 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 23:09:23 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 23:09:23 volumio volumio[22182]: info: No need to fix Spotify hosts Jan 26 23:09:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:09:23 volumio go-librespot[22438]: go-librespot daemon starting... Jan 26 23:09:23 volumio sudo[22429]: pam_unix(sudo:session): session closed for user root Jan 26 23:09:23 volumio go-librespot[22442]: time="2026-01-26T23:09:23+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 23:09:23 volumio go-librespot[22442]: time="2026-01-26T23:09:23+07:00" level=debug msg="app state loaded" Jan 26 23:09:23 volumio go-librespot[22442]: time="2026-01-26T23:09:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 23:09:23 volumio go-librespot[22442]: time="2026-01-26T23:09:23+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]" Jan 26 23:09:23 volumio go-librespot[22442]: time="2026-01-26T23:09:23+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]" Jan 26 23:09:23 volumio go-librespot[22442]: time="2026-01-26T23:09:23+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]" Jan 26 23:09:23 volumio go-librespot[22442]: time="2026-01-26T23:09:23+07:00" level=info msg="zeroconf server listening on port 43445" Jan 26 23:09:24 volumio go-librespot[22442]: time="2026-01-26T23:09:24+07:00" level=debug msg="obtained new client token: AACMIyWwWcnj1egY6eogtkrM/MmXlz5nLJKuWtEOsSsqAmBDb12Zmi5igAfcVR8Awn/ZqCkpY/FzByII51eYP++I9+Byg1xA0oG+FYTHfvwNeNHhl3+08J9w3d6RwKsJEh2LJ6OVZ+zeSpXkOr6TaR3Z836uqgPSPHZOPZWB/YcZYBA8NZV2BrodQ043JtkLBGaPmJPeatsA7CyZVeKwJjm1rM4SP/1WYfRYllL3vsgOUV6GWmMIljY0" Jan 26 23:09:24 volumio go-librespot[22442]: time="2026-01-26T23:09:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 23:09:24 volumio volumio[22182]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 23:09:24 volumio volumio[22182]: SPOTIFY: BQCGFoDnY5QIJeEmpncJKz9iOj2Mznn7y_WmZV1pTLNIaQTGr-SZ7hu7FOPWcujObvrk5xlh_c9m9wIkWJp_EMe-8HmjwnZ6ijk1E4HYvtb3N0ca50vM-i2ku6s8v0tJx4RakbnnZUiuWzOB2pZVMWnbfHiMePb7uwoQHenzbEK6LfR3Odk72GA0qEb5fZNl5HeDzrwf2azkfc46IglIRzRFesLTjsPYu9ZBjGunSCmTCsmRdmjBidLGcv1DO9QHwIrGc-u0gvrT3WkuQLeggv43xX9VNj1V6IceoFWnyarcgG6URt2CQW6J Jan 26 23:09:24 volumio volumio[22182]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 23:09:24 volumio volumio[22182]: info: New Spotify access token = BQCGFoDnY5QIJeEmpncJKz9iOj2Mznn7y_WmZV1pTLNIaQTGr-SZ7hu7FOPWcujObvrk5xlh_c9m9wIkWJp_EMe-8HmjwnZ6ijk1E4HYvtb3N0ca50vM-i2ku6s8v0tJx4RakbnnZUiuWzOB2pZVMWnbfHiMePb7uwoQHenzbEK6LfR3Odk72GA0qEb5fZNl5HeDzrwf2azkfc46IglIRzRFesLTjsPYu9ZBjGunSCmTCsmRdmjBidLGcv1DO9QHwIrGc-u0gvrT3WkuQLeggv43xX9VNj1V6IceoFWnyarcgG6URt2CQW6J Jan 26 23:09:24 volumio volumio[22182]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 26 23:09:24 volumio volumio[22182]: info: Starting Shairport Sync Jan 26 23:09:24 volumio go-librespot[22442]: time="2026-01-26T23:09:24+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 23:09:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 23:09:24 volumio volumio[22182]: info: Starting Shairport Sync Jan 26 23:09:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 23:09:24 volumio sudo[22468]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 23:09:24 volumio sudo[22468]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:09:24 volumio volumio[22182]: info: Starting Shairport Sync Jan 26 23:09:24 volumio sudo[22470]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 23:09:24 volumio sudo[22470]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:09:24 volumio sudo[22474]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 23:09:24 volumio sudo[22474]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:09:24 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 26 23:09:24 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 26 23:09:24 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 23:09:24 volumio systemd[1]: shairport-sync.service: Consumed 2.436s CPU time. Jan 26 23:09:24 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 23:09:24 volumio sudo[22474]: pam_unix(sudo:session): session closed for user root Jan 26 23:09:24 volumio sudo[22468]: pam_unix(sudo:session): session closed for user root Jan 26 23:09:24 volumio sudo[22470]: pam_unix(sudo:session): session closed for user root Jan 26 23:09:24 volumio volumio[22182]: info: Shairport-Sync Started Jan 26 23:09:24 volumio volumio[22182]: Error adding Membership: Error: addMembership EINVAL Jan 26 23:09:24 volumio volumio[22182]: info: Shairport-Sync Started Jan 26 23:09:24 volumio volumio[22182]: info: Shairport-Sync Started Jan 26 23:09:24 volumio volumio[22182]: info: CoreCommandRouter::volumioGetState Jan 26 23:09:24 volumio volumio[22182]: info: CorePlayQueue::getTrack 0 Jan 26 23:09:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:09:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:09:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:09:25 volumio volumio[22182]: 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"} Jan 26 23:09:25 volumio volumio[22182]: info: Spotify Successfully logged in Jan 26 23:09:25 volumio volumio[22182]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 23:09:25 volumio volumio[22182]: info: [1769443765214] CoreMusicLibrary::Adding element Spotify Jan 26 23:09:25 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 23:09:25 volumio volumio[22182]: Cannot find translation for source YouTube Music Jan 26 23:09:25 volumio volumio[22182]: Cannot find translation for source Spotify Jan 26 23:09:25 volumio volumio[22182]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 26 23:09:25 volumio volumio[22182]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 23:09:26 volumio volumio[22182]: info: VolumeController:: Volume=100 Mute =false Jan 26 23:09:26 volumio volumio[22182]: info: CoreCommandRouter::volumioGetState Jan 26 23:09:26 volumio volumio[22182]: info: CorePlayQueue::getTrack 0 Jan 26 23:09:26 volumio volumio[22182]: info: CoreStateMachine::pushState Jan 26 23:09:26 volumio volumio[22182]: info: CorePlayQueue::getTrack 0 Jan 26 23:09:26 volumio volumio[22182]: info: CoreCommandRouter::volumioPushState Jan 26 23:09:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:09:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:09:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:09:27 volumio volumio[22182]: info: go-librespot daemon successfully initialized Jan 26 23:09:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 26 23:09:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:09:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:09:27 volumio go-librespot[22508]: go-librespot daemon starting... Jan 26 23:09:27 volumio go-librespot[22509]: time="2026-01-26T23:09:27+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 23:09:27 volumio go-librespot[22509]: time="2026-01-26T23:09:27+07:00" level=debug msg="app state loaded" Jan 26 23:09:27 volumio go-librespot[22509]: time="2026-01-26T23:09:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 23:09:27 volumio mpd[22413]: 2026-01-26T23:09:27 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 26 23:09:27 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 26 23:09:27 volumio sudo[22373]: pam_unix(sudo:session): session closed for user root Jan 26 23:09:27 volumio sudo[22383]: pam_unix(sudo:session): session closed for user root Jan 26 23:09:28 volumio go-librespot[22509]: time="2026-01-26T23:09:28+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]" Jan 26 23:09:28 volumio go-librespot[22509]: time="2026-01-26T23:09:28+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]" Jan 26 23:09:28 volumio go-librespot[22509]: time="2026-01-26T23:09:28+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]" Jan 26 23:09:28 volumio volumio[22182]: error: MPD error: The expression evaluated to a falsy value: Jan 26 23:09:28 volumio volumio[22182]: assert.ok(self.idling) Jan 26 23:09:28 volumio volumio[22182]: error: The expression evaluated to a falsy value: Jan 26 23:09:28 volumio volumio[22182]: assert.ok(self.idling) Jan 26 23:09:28 volumio volumio[22182]: error: updateQueue error: null Jan 26 23:09:28 volumio go-librespot[22509]: time="2026-01-26T23:09:28+07:00" level=info msg="zeroconf server listening on port 37809" Jan 26 23:09:28 volumio volumio[22182]: info: MPD running with PID22413 Jan 26 23:09:28 volumio volumio[22182]: ,establishing connection Jan 26 23:09:28 volumio volumio[22182]: info: Completed starting Core Plugins Jan 26 23:09:28 volumio volumio[22182]: info: ------------------------------------------- Jan 26 23:09:28 volumio volumio[22182]: info: ----- MyVolumio plugins startup ---- Jan 26 23:09:28 volumio volumio[22182]: info: ------------------------------------------- Jan 26 23:09:28 volumio volumio[22182]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 26 23:09:28 volumio volumio[22182]: error: updateQueue error: null Jan 26 23:09:28 volumio go-librespot[22509]: time="2026-01-26T23:09:28+07:00" level=debug msg="obtained new client token: AAD1aoYO4cgFnkE8uTzPy4Sjrx4PBATFvK+kVJ0rcCKe2eftxdWfkeKalXmNlK2O60erVa0Lk5D3pdHy8jScblmBHs9eM9a4YHciRY2xxAUAYZHGOfqEelWxzRT2+yqgGd6xnj84XfK6n60dhJScDCSRgKb1gLkpKzwiob1TFVU69mpqnVXXW1RTppWRVNEfYURf+Q4SEeAwOo22wULn5btLtpt4VaJe/OZXpE+/ruzVX2WcKiWp6urzi6k=" Jan 26 23:09:28 volumio go-librespot[22509]: time="2026-01-26T23:09:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 23:09:28 volumio go-librespot[22509]: time="2026-01-26T23:09:28+07:00" level=debug msg="completed keyexchange" Jan 26 23:09:28 volumio go-librespot[22509]: time="2026-01-26T23:09:28+07:00" level=debug msg="completed challenge" Jan 26 23:09:28 volumio go-librespot[22509]: time="2026-01-26T23:09:28+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 " Jan 26 23:09:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 23:09:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 23:09:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:09:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:09:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:09:30 volumio volumio[22182]: info: Initializing connection to go-librespot Websocket Jan 26 23:09:30 volumio volumio[22182]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 23:09:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:09:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:09:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:09:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 26 23:09:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:09:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:09:31 volumio go-librespot[22521]: go-librespot daemon starting... Jan 26 23:09:31 volumio go-librespot[22522]: time="2026-01-26T23:09:31+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 23:09:31 volumio go-librespot[22522]: time="2026-01-26T23:09:31+07:00" level=debug msg="app state loaded" Jan 26 23:09:31 volumio go-librespot[22522]: time="2026-01-26T23:09:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 23:09:32 volumio go-librespot[22522]: time="2026-01-26T23:09:32+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]" Jan 26 23:09:32 volumio go-librespot[22522]: time="2026-01-26T23:09:32+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]" Jan 26 23:09:32 volumio go-librespot[22522]: time="2026-01-26T23:09:32+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]" Jan 26 23:09:32 volumio go-librespot[22522]: time="2026-01-26T23:09:32+07:00" level=info msg="zeroconf server listening on port 40769" Jan 26 23:09:32 volumio go-librespot[22522]: time="2026-01-26T23:09:32+07:00" level=debug msg="obtained new client token: AAC7N9d14U1kvvW2YZoturXZWpy5WSRchyRFyDYVAlY6tmHVy7OriHoJ17y5Fe3wUxNiODSkIBG7S31HtpcpV+5QpzYRd4xXe/dWFaQpDNIuSt4nvy+Vqpbo9BYFdjpIoIBeO17y2nZaae6GyyR+T7cpfFsH3smxy7EWH1jyxkXTtSKFy4oqnlvvuTsxn/K/99KXZa2+aFYoEV/RAHdxFQDmKb7dd+PwBW1WImfX06UO9Mu9q/gnWB8orCE=" Jan 26 23:09:32 volumio go-librespot[22522]: time="2026-01-26T23:09:32+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" Jan 26 23:09:32 volumio go-librespot[22522]: time="2026-01-26T23:09:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 26 23:09:32 volumio go-librespot[22522]: time="2026-01-26T23:09:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 23:09:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 23:09:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 23:09:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:09:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:09:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:09:33 volumio volumio[22182]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 26 23:09:33 volumio volumio[22182]: info: Initializing connection to go-librespot Websocket Jan 26 23:09:33 volumio volumio[22182]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 23:09:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:09:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:09:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:09:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 26 23:09:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:09:36 volumio volumio[22182]: info: Initializing connection to go-librespot Websocket Jan 26 23:09:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:09:36 volumio go-librespot[22531]: go-librespot daemon starting... Jan 26 23:09:36 volumio go-librespot[22532]: time="2026-01-26T23:09:36+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 23:09:36 volumio go-librespot[22532]: time="2026-01-26T23:09:36+07:00" level=debug msg="app state loaded" Jan 26 23:09:36 volumio go-librespot[22532]: time="2026-01-26T23:09:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 23:09:36 volumio volumio[22182]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 23:09:36 volumio go-librespot[22532]: time="2026-01-26T23:09:36+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]" Jan 26 23:09:36 volumio go-librespot[22532]: time="2026-01-26T23:09:36+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]" Jan 26 23:09:36 volumio go-librespot[22532]: time="2026-01-26T23:09:36+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]" Jan 26 23:09:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:09:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:09:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:09:37 volumio go-librespot[22532]: time="2026-01-26T23:09:37+07:00" level=info msg="zeroconf server listening on port 35069" Jan 26 23:09:37 volumio go-librespot[22532]: time="2026-01-26T23:09:37+07:00" level=debug msg="obtained new client token: AABA8xC5914QvO/pgAVFRbhHnRmbmG40Zmichtk/yor2fILjA78GPf7BnpEOtPYg85lTzG5GcX6qE+efkatBcT86XpR6tkkyPj5dIjPF5RTXvrJWbR6UyUi71iSA3kvuZEIQDX7NFbvZem9NH/TOlV+IeBvjWD69ExbV7V03FAGw985e7DB+RHSxasiEJqFVObzmGIq0yZNPxXgodxACs9MJF36n7fpSoSIzh1yL9L/u6QX9jSzxAmFh" Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 26 23:09:37 volumio volumio[22182]: info: Adding plugin bluetooth to MyMusic Plugins Jan 26 23:09:37 volumio volumio[22182]: info: Adding plugin multiroom to MyMusic Plugins Jan 26 23:09:37 volumio volumio[22182]: info: Adding plugin metavolumio to MyMusic Plugins Jan 26 23:09:37 volumio volumio[22182]: info: Adding plugin cd_controller to MyMusic Plugins Jan 26 23:09:37 volumio volumio[22182]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 26 23:09:37 volumio volumio[22182]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 26 23:09:37 volumio volumio[22182]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 26 23:09:37 volumio volumio[22182]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 26 23:09:37 volumio go-librespot[22532]: time="2026-01-26T23:09:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 23:09:37 volumio go-librespot[22532]: time="2026-01-26T23:09:37+07:00" level=debug msg="completed keyexchange" Jan 26 23:09:37 volumio go-librespot[22532]: time="2026-01-26T23:09:37+07:00" level=debug msg="completed challenge" Jan 26 23:09:37 volumio go-librespot[22532]: time="2026-01-26T23:09:37+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 " Jan 26 23:09:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 23:09:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 23:09:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:09:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:09:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:09:39 volumio volumio[22182]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 26 23:09:39 volumio volumio[22182]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 26 23:09:39 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 23:09:39 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 23:09:39 volumio volumio[22182]: info: Starting MyVolumio Remote Streaming Endpoints Jan 26 23:09:39 volumio volumio[22182]: info: MyVolumio login type: Token Jan 26 23:09:39 volumio volumio[22182]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 26 23:09:39 volumio volumio[22182]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 26 23:09:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 26 23:09:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:09:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:09:40 volumio go-librespot[22554]: go-librespot daemon starting... Jan 26 23:09:40 volumio go-librespot[22555]: time="2026-01-26T23:09:40+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 23:09:40 volumio go-librespot[22555]: time="2026-01-26T23:09:40+07:00" level=debug msg="app state loaded" Jan 26 23:09:40 volumio go-librespot[22555]: time="2026-01-26T23:09:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 23:09:40 volumio volumio[22182]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 26 23:09:40 volumio volumio[22182]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 26 23:09:40 volumio volumio[22182]: info: Streaming services startup Jan 26 23:09:40 volumio volumio[22182]: info: Starting Streaming Daemon Jan 26 23:09:40 volumio sudo[22563]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 26 23:09:40 volumio sudo[22563]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:09:40 volumio volumio[22182]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 26 23:09:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:09:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:09:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:09:41 volumio sudo[22563]: pam_unix(sudo:session): session closed for user root Jan 26 23:09:41 volumio volumio[22182]: info: Initializing connection to go-librespot Websocket Jan 26 23:09:41 volumio volumio[22182]: error: Cannot start Volumio Streaming Daemon Jan 26 23:09:41 volumio volumio[22182]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 26 23:09:41 volumio volumio[22182]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 26 23:09:41 volumio go-librespot[22555]: time="2026-01-26T23:09:41+07:00" level=debug msg="new websocket client" Jan 26 23:09:41 volumio volumio[22182]: info: Connection to go-librespot Websocket established Jan 26 23:09:41 volumio go-librespot[22555]: time="2026-01-26T23:09:41+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]" Jan 26 23:09:41 volumio go-librespot[22555]: time="2026-01-26T23:09:41+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]" Jan 26 23:09:41 volumio go-librespot[22555]: time="2026-01-26T23:09:41+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]" Jan 26 23:09:41 volumio go-librespot[22555]: time="2026-01-26T23:09:41+07:00" level=info msg="zeroconf server listening on port 34937" Jan 26 23:09:41 volumio go-librespot[22555]: time="2026-01-26T23:09:41+07:00" level=debug msg="obtained new client token: AAAmfibYmqiLHPrCiAnmPDaVQwwrWlgRJ4Pjy49IrDY6fdbDP85duyMHPOalynRs3hH/FAZ3xjYAe+iBFx+UlKCgu6MOSih7oQHTwQqDdAKmGb4LSVWqEuHWEQY9b085WmY4/YENMCLS8hiX1cn9yq5farvNhjkzttX4OGPynF7JQYh9/Bs8bfFvTGbql5aP0kuXMo5PHaL7pTcfYq/juZsUDHeD/cUSCi/TJId+I+aHBVXDUQQdc7lIdG0=" Jan 26 23:09:41 volumio go-librespot[22555]: time="2026-01-26T23:09:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 23:09:41 volumio go-librespot[22555]: time="2026-01-26T23:09:41+07:00" level=debug msg="completed keyexchange" Jan 26 23:09:41 volumio go-librespot[22555]: time="2026-01-26T23:09:41+07:00" level=debug msg="completed challenge" Jan 26 23:09:41 volumio go-librespot[22555]: time="2026-01-26T23:09:41+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 " Jan 26 23:09:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 23:09:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 23:09:42 volumio volumio[22182]: info: Connection to go-librespot Websocket closed Jan 26 23:09:42 volumio volumio[22182]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 26 23:09:42 volumio volumio[22182]: info: MyVolumio token set successfully Jan 26 23:09:42 volumio volumio[22182]: info: MYVOLUMIO: Adding device Jan 26 23:09:42 volumio volumio[22182]: info: MYVOLUMIO: Evaluating Server Jan 26 23:09:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:09:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:09:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:09:43 volumio volumio[22182]: info: MyVolumio status changed Jan 26 23:09:43 volumio volumio[22182]: info: Streaming services startup Jan 26 23:09:43 volumio volumio[22182]: info: Starting Streaming Daemon Jan 26 23:09:43 volumio volumio[22182]: info: Removing browser output: myVolumio user plan is not superstar Jan 26 23:09:43 volumio volumio[22182]: info: Removing audio output: Jan 26 23:09:43 volumio volumio[22182]: info: Stoppping Tunnel 1 Jan 26 23:09:43 volumio sudo[22591]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 26 23:09:43 volumio sudo[22591]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:09:43 volumio sudo[22593]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 26 23:09:43 volumio sudo[22593]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:09:43 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. Jan 26 23:09:43 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. Jan 26 23:09:43 volumio sudo[22591]: pam_unix(sudo:session): session closed for user root Jan 26 23:09:43 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. Jan 26 23:09:43 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. Jan 26 23:09:43 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. Jan 26 23:09:43 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. Jan 26 23:09:43 volumio sudo[22593]: pam_unix(sudo:session): session closed for user root Jan 26 23:09:43 volumio volumio[22182]: error: Cannot start Volumio Streaming Daemon Jan 26 23:09:43 volumio volumio[22182]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 26 23:09:43 volumio volumio[22182]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 26 23:09:43 volumio volumio[22182]: info: Remote SSH Stopped Jan 26 23:09:44 volumio volumio[22182]: info: Setting Geolocation for MyVolumio to as1 Jan 26 23:09:44 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 23:09:44 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 23:09:44 volumio volumio[22182]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 23:09:44 volumio volumio[22182]: info: Getting Spotify volume Jan 26 23:09:44 volumio volumio[22182]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 23:09:44 volumio volumio[22182]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 23:09:44 volumio volumio[22182]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 26 23:09:44 volumio volumio[22182]: errno: -111, Jan 26 23:09:44 volumio volumio[22182]: code: 'ECONNREFUSED', Jan 26 23:09:44 volumio volumio[22182]: syscall: 'connect', Jan 26 23:09:44 volumio volumio[22182]: address: '127.0.0.1', Jan 26 23:09:44 volumio volumio[22182]: port: 9879, Jan 26 23:09:44 volumio volumio[22182]: response: undefined Jan 26 23:09:44 volumio volumio[22182]: } Jan 26 23:09:44 volumio volumio[22182]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 23:09:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 23:09:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 23:09:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 23:09:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 26 23:09:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:09:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 23:09:45 volumio go-librespot[22608]: go-librespot daemon starting... Jan 26 23:09:45 volumio go-librespot[22609]: time="2026-01-26T23:09:45+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 23:09:45 volumio go-librespot[22609]: time="2026-01-26T23:09:45+07:00" level=debug msg="app state loaded" Jan 26 23:09:45 volumio go-librespot[22609]: time="2026-01-26T23:09:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 23:09:45 volumio sudo[22618]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-26 23:08' Jan 26 23:09:45 volumio sudo[22618]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 23:09:45 volumio go-librespot[22609]: time="2026-01-26T23:09:45+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]" Jan 26 23:09:45 volumio go-librespot[22609]: time="2026-01-26T23:09:45+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]" Jan 26 23:09:45 volumio go-librespot[22609]: time="2026-01-26T23:09:45+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]" Jan 26 23:09:45 volumio go-librespot[22609]: time="2026-01-26T23:09:45+07:00" level=info msg="zeroconf server listening on port 39959" Jan 26 23:09:46 volumio go-librespot[22609]: time="2026-01-26T23:09:46+07:00" level=debug msg="obtained new client token: AADqIb1eUlr6VEBOIooeqVtv33zg2Pns11ZvI856514gDaRzc7VnZO9tBKk8PQ2i2rZGGpuDxcea+7WPWYFbITQLB/iQNDBUxWrqqMM7BYhzwPSO4DvcfzMTmEbzmyNxRJhmkt8Qf7Y35U8T8eOvSZcG/DrH+GoikJ9uyFqFloJIJVT+a4e8bSTc2tRQZjq3abrp6OMdJYH0DfgJFH3QpYrBMHU9DDVVKdLrBgMbWKZ0fQif6JHMQnmw" 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"