Feb 10 14:50:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 113. Feb 10 14:50:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:00 volumio go-librespot[9523]: go-librespot daemon starting... Feb 10 14:50:00 volumio go-librespot[9524]: time="2026-02-10T14:50:00-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:50:00 volumio go-librespot[9524]: time="2026-02-10T14:50:00-06:00" level=debug msg="app state loaded" Feb 10 14:50:00 volumio go-librespot[9524]: time="2026-02-10T14:50:00-06:00" level=debug msg="stored credentials not found" Feb 10 14:50:00 volumio go-librespot[9524]: time="2026-02-10T14:50:00-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:50:00 volumio go-librespot[9524]: time="2026-02-10T14:50:00-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 14:50:00 volumio go-librespot[9524]: time="2026-02-10T14:50:00-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 14:50:00 volumio go-librespot[9524]: time="2026-02-10T14:50:00-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 14:50:00 volumio go-librespot[9524]: time="2026-02-10T14:50:00-06:00" level=info msg="zeroconf server listening on port 35831" Feb 10 14:50:00 volumio go-librespot[9524]: time="2026-02-10T14:50:00-06:00" level=debug msg="obtained new client token: AABGSE5u9SrKOekuHrKyZrIxwnQyhDtQgtFYXFYzO9jKNrKelZLfzZ97eQg7Bl1yv0OzVQ4VFWa35Du+lfWETrYaJXOeYGhjqRL0Og6FLEEtIol0li6/fIuQOz6G3VALtbevfbiqFsDUDH3jcekLXXsgLzFeI0nDUKwSySxo0bLW6R4el6ym3xwHQ9xRMRvsKeiZhd88nCSP1/HbKc2ZELkbPrDyMA2gCC4dHNvJxTFJGxecCqvZudkDFA==" Feb 10 14:50:00 volumio go-librespot[9524]: time="2026-02-10T14:50:00-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 14:50:00 volumio go-librespot[9524]: time="2026-02-10T14:50:00-06:00" level=debug msg="completed keyexchange" Feb 10 14:50:00 volumio go-librespot[9524]: time="2026-02-10T14:50:00-06:00" level=debug msg="completed challenge" Feb 10 14:50:00 volumio go-librespot[9524]: time="2026-02-10T14:50:00-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:50:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:50:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:50:00 volumio volumio[8892]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Feb 10 14:50:00 volumio volumio[8892]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 10 14:50:01 volumio volumio[8892]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Feb 10 14:50:01 volumio volumio[8892]: info: Initializing connection to go-librespot Websocket Feb 10 14:50:01 volumio volumio[8892]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 14:50:03 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 10 14:50:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 114. Feb 10 14:50:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:04 volumio go-librespot[9535]: go-librespot daemon starting... Feb 10 14:50:04 volumio volumio[8892]: info: Initializing connection to go-librespot Websocket Feb 10 14:50:04 volumio volumio[8892]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 14:50:04 volumio go-librespot[9536]: time="2026-02-10T14:50:04-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:50:04 volumio go-librespot[9536]: time="2026-02-10T14:50:04-06:00" level=debug msg="app state loaded" Feb 10 14:50:04 volumio go-librespot[9536]: time="2026-02-10T14:50:04-06:00" level=debug msg="stored credentials not found" Feb 10 14:50:04 volumio go-librespot[9536]: time="2026-02-10T14:50:04-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:50:04 volumio go-librespot[9536]: time="2026-02-10T14:50:04-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 14:50:04 volumio go-librespot[9536]: time="2026-02-10T14:50:04-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 14:50:04 volumio go-librespot[9536]: time="2026-02-10T14:50:04-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 14:50:04 volumio go-librespot[9536]: time="2026-02-10T14:50:04-06:00" level=info msg="zeroconf server listening on port 46067" Feb 10 14:50:04 volumio go-librespot[9536]: time="2026-02-10T14:50:04-06:00" level=debug msg="obtained new client token: AAB+s+oMz/7EjAKicVxmFCh5FfmTkxEf7FgkSp16BUX84jkmXbaz18IthyKZ6MzY+UZgUT+6IgpQf7hA/xoVrAK5cJ/kMUGf299FIa+MbBirfABVXvZ1l4j+hTCXy9K7ymDOtE/Xg1FRhsoFtAEpi2xrWmNZVewFYXbMcFxJtr+4gQYk+xpSD7IQzC3YU6b/RFXsu54R0CkJC2NfDCOfIGMef9YHQK2ieZ55XkJK91DsA2f3KCzeT6v5xw==" Feb 10 14:50:04 volumio go-librespot[9536]: time="2026-02-10T14:50:04-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 14:50:04 volumio go-librespot[9536]: time="2026-02-10T14:50:04-06:00" level=debug msg="completed keyexchange" Feb 10 14:50:04 volumio go-librespot[9536]: time="2026-02-10T14:50:04-06:00" level=debug msg="completed challenge" Feb 10 14:50:04 volumio go-librespot[9536]: time="2026-02-10T14:50:04-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:50:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:50:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:50:06 volumio volumio[8892]: info: BOOT COMPLETED Feb 10 14:50:07 volumio volumio[8892]: info: Initializing connection to go-librespot Websocket Feb 10 14:50:07 volumio volumio[8892]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 14:50:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 115. Feb 10 14:50:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:08 volumio go-librespot[9557]: go-librespot daemon starting... Feb 10 14:50:08 volumio go-librespot[9558]: time="2026-02-10T14:50:08-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:50:08 volumio go-librespot[9558]: time="2026-02-10T14:50:08-06:00" level=debug msg="app state loaded" Feb 10 14:50:08 volumio go-librespot[9558]: time="2026-02-10T14:50:08-06:00" level=debug msg="stored credentials not found" Feb 10 14:50:08 volumio go-librespot[9558]: time="2026-02-10T14:50:08-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:50:08 volumio go-librespot[9558]: time="2026-02-10T14:50:08-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 14:50:08 volumio go-librespot[9558]: time="2026-02-10T14:50:08-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 14:50:08 volumio go-librespot[9558]: time="2026-02-10T14:50:08-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 14:50:08 volumio go-librespot[9558]: time="2026-02-10T14:50:08-06:00" level=info msg="zeroconf server listening on port 35451" Feb 10 14:50:08 volumio go-librespot[9558]: time="2026-02-10T14:50:08-06:00" level=debug msg="obtained new client token: AAD3O//Xcovv5mm6/3dEY/HW1GBpdGFY5qTcd6KpD7+uOQ9SQiJAIF10CLK/agEZi4IuIBzaWdzrgCw1rJerCXK7cuVRm3hNOviAIfau9v7Niw0+dso0metSonrq8pfZjRa6wgdjrCF03VKXtDObupdTQKbVd1TETRRtpLLZgHRWIV+5Lxw890lERTQYoQaKQ7ZQiOiYY5B0fyHxvULVj6DBI/Y6AqcbmvHqQBLWyEeeVwvthRBwykO+tQ==" Feb 10 14:50:08 volumio go-librespot[9558]: time="2026-02-10T14:50:08-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 14:50:08 volumio go-librespot[9558]: time="2026-02-10T14:50:08-06:00" level=debug msg="completed keyexchange" Feb 10 14:50:08 volumio go-librespot[9558]: time="2026-02-10T14:50:08-06:00" level=debug msg="completed challenge" Feb 10 14:50:08 volumio go-librespot[9558]: time="2026-02-10T14:50:08-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:50:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:50:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:50:09 volumio kernel: hwmon hwmon1: Voltage normalised Feb 10 14:50:10 volumio volumio[8892]: info: Initializing connection to go-librespot Websocket Feb 10 14:50:10 volumio volumio[8892]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 14:50:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 116. Feb 10 14:50:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:11 volumio go-librespot[9569]: go-librespot daemon starting... Feb 10 14:50:11 volumio go-librespot[9570]: time="2026-02-10T14:50:11-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:50:11 volumio go-librespot[9570]: time="2026-02-10T14:50:11-06:00" level=debug msg="app state loaded" Feb 10 14:50:11 volumio go-librespot[9570]: time="2026-02-10T14:50:11-06:00" level=debug msg="stored credentials not found" Feb 10 14:50:11 volumio go-librespot[9570]: time="2026-02-10T14:50:11-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:50:12 volumio go-librespot[9570]: time="2026-02-10T14:50:12-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 14:50:12 volumio go-librespot[9570]: time="2026-02-10T14:50:12-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 10 14:50:12 volumio go-librespot[9570]: time="2026-02-10T14:50:12-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 10 14:50:12 volumio go-librespot[9570]: time="2026-02-10T14:50:12-06:00" level=info msg="zeroconf server listening on port 40861" Feb 10 14:50:12 volumio go-librespot[9570]: time="2026-02-10T14:50:12-06:00" level=debug msg="obtained new client token: AABnaMMB0ft6K5716QlSf1FbVAbjT8qHOhNjcoD//EZbQ/FnUrAIsK07kqhUu/J8yViL2bssbMB4xHdDQyMyC7CL0+CbqfW+r4BXg3Bq6AwmdDtn/2soF1yG46epDCvRUhS54QHoD81pqsUBkDL5rHOHaMjEIDYqcSYSQ+lzJjE+4efnkUJYEUK5ouPEtF9+pvHGyEc13nHS1v5BlVT8mqG64XFZnQyNFLuC2ePpplDWHh+p/aO8/t8=" Feb 10 14:50:12 volumio go-librespot[9570]: time="2026-02-10T14:50:12-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 14:50:12 volumio go-librespot[9570]: time="2026-02-10T14:50:12-06:00" level=debug msg="completed keyexchange" Feb 10 14:50:12 volumio go-librespot[9570]: time="2026-02-10T14:50:12-06:00" level=debug msg="completed challenge" Feb 10 14:50:12 volumio go-librespot[9570]: time="2026-02-10T14:50:12-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:50:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:50:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:50:13 volumio volumio[8892]: info: Initializing connection to go-librespot Websocket Feb 10 14:50:13 volumio volumio[8892]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 14:50:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 117. Feb 10 14:50:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:15 volumio go-librespot[9584]: go-librespot daemon starting... Feb 10 14:50:15 volumio go-librespot[9592]: time="2026-02-10T14:50:15-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:50:15 volumio go-librespot[9592]: time="2026-02-10T14:50:15-06:00" level=debug msg="app state loaded" Feb 10 14:50:15 volumio go-librespot[9592]: time="2026-02-10T14:50:15-06:00" level=debug msg="stored credentials not found" Feb 10 14:50:15 volumio go-librespot[9592]: time="2026-02-10T14:50:15-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:50:15 volumio go-librespot[9592]: time="2026-02-10T14:50:15-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 14:50:15 volumio go-librespot[9592]: time="2026-02-10T14:50:15-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 10 14:50:15 volumio go-librespot[9592]: time="2026-02-10T14:50:15-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 10 14:50:15 volumio go-librespot[9592]: time="2026-02-10T14:50:15-06:00" level=info msg="zeroconf server listening on port 46087" Feb 10 14:50:16 volumio go-librespot[9592]: time="2026-02-10T14:50:16-06:00" level=debug msg="obtained new client token: AACSCxOw+jaFGWSyWOPQC529mspfNIB/2x3qTa0T1nsEBVjgvXSIY7ZQyyzxQP0ZlCLF4uEVArfvei1rkOysXXZqzFcZNedyrTI1cYvIKmWyX0aJj4cKw6x1lRkVK83zErur1p8Z0DhbngO88fVgfuudQnoM1smg+ABLKUhcv5Lzs3ERw7J37YSo27cIj0zHZtszaQnOk8wTxNJ/h4sezRCm1uV6R0Indf5yPZu0BpQ5zGxfPYEptu7mUA==" Feb 10 14:50:16 volumio go-librespot[9592]: time="2026-02-10T14:50:16-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 14:50:16 volumio go-librespot[9592]: time="2026-02-10T14:50:16-06:00" level=debug msg="completed keyexchange" Feb 10 14:50:16 volumio go-librespot[9592]: time="2026-02-10T14:50:16-06:00" level=debug msg="completed challenge" Feb 10 14:50:16 volumio volumio[8892]: info: Initializing connection to go-librespot Websocket Feb 10 14:50:16 volumio go-librespot[9592]: time="2026-02-10T14:50:16-06:00" level=debug msg="new websocket client" Feb 10 14:50:16 volumio volumio[8892]: info: Connection to go-librespot Websocket established Feb 10 14:50:16 volumio go-librespot[9592]: time="2026-02-10T14:50:16-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:50:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:50:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:50:16 volumio volumio[8892]: info: Connection to go-librespot Websocket closed Feb 10 14:50:19 volumio volumio[8892]: info: Getting Spotify volume Feb 10 14:50:19 volumio volumio[8892]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 14:50:19 volumio volumio[8892]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 14:50:19 volumio volumio[8892]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 10 14:50:19 volumio volumio[8892]: errno: -111, Feb 10 14:50:19 volumio volumio[8892]: code: 'ECONNREFUSED', Feb 10 14:50:19 volumio volumio[8892]: syscall: 'connect', Feb 10 14:50:19 volumio volumio[8892]: address: '127.0.0.1', Feb 10 14:50:19 volumio volumio[8892]: port: 9879, Feb 10 14:50:19 volumio volumio[8892]: response: undefined Feb 10 14:50:19 volumio volumio[8892]: } Feb 10 14:50:19 volumio volumio[8892]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 14:50:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 118. Feb 10 14:50:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:19 volumio go-librespot[9611]: go-librespot daemon starting... Feb 10 14:50:19 volumio go-librespot[9613]: time="2026-02-10T14:50:19-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:50:19 volumio go-librespot[9613]: time="2026-02-10T14:50:19-06:00" level=debug msg="app state loaded" Feb 10 14:50:19 volumio go-librespot[9613]: time="2026-02-10T14:50:19-06:00" level=debug msg="stored credentials not found" Feb 10 14:50:19 volumio go-librespot[9613]: time="2026-02-10T14:50:19-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:50:19 volumio go-librespot[9613]: time="2026-02-10T14:50:19-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 14:50:19 volumio go-librespot[9613]: time="2026-02-10T14:50:19-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 10 14:50:19 volumio go-librespot[9613]: time="2026-02-10T14:50:19-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 10 14:50:19 volumio go-librespot[9613]: time="2026-02-10T14:50:19-06:00" level=info msg="zeroconf server listening on port 41099" Feb 10 14:50:19 volumio go-librespot[9613]: time="2026-02-10T14:50:19-06:00" level=debug msg="obtained new client token: AAAnwi4aLl88abWqvJWoULheQhyuVyj8aLByqcElCG1GfPJPC8SuD9rDv5qHwOjCUf7cFPO+QTZzANVrNOBjD7JJCn1w3sp6SHaDb+n9s7JzS39G9m+1aa4LoKsuslYY4Bpz9RPFzTfssoR7VNdgOt0hg2H0JBFUlLEoadfmhTxc/9LZrdjqM4cpx/anojHg5hVewKiKAs2ecrLfw+IQ4bY/u8DyStVJysVT7Ezg6EqcjAKBeDS79x+8rQ==" Feb 10 14:50:19 volumio go-librespot[9613]: time="2026-02-10T14:50:19-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 14:50:19 volumio go-librespot[9613]: time="2026-02-10T14:50:19-06:00" level=debug msg="completed keyexchange" Feb 10 14:50:19 volumio go-librespot[9613]: time="2026-02-10T14:50:19-06:00" level=debug msg="completed challenge" Feb 10 14:50:19 volumio go-librespot[9613]: time="2026-02-10T14:50:19-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:50:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:50:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:50:19 volumio sudo[9622]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-10 14:49' Feb 10 14:50:19 volumio sudo[9622]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:20 volumio sudo[9622]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:20 volumio volumio-remote-updater[751]: [2026-02-10 14:50:20] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 10 14:50:20 volumio volumio-remote-updater[751]: [2026-02-10 14:50:20] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 10 14:50:20 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:50:20 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 10 14:50:20 volumio systemd[1]: volumio.service: Consumed 58.685s CPU time. Feb 10 14:50:20 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 14:50:20 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 14:50:20 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 4139. Feb 10 14:50:20 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 14:50:20 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 10 14:50:20 volumio systemd[1]: volumio.service: Consumed 58.685s CPU time. Feb 10 14:50:20 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 10 14:50:20 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 14:50:22 volumio volumio[9639]: info: ------------------------------------------- Feb 10 14:50:22 volumio volumio[9639]: info: ----- Volumio3 ---- Feb 10 14:50:22 volumio volumio[9639]: info: ------------------------------------------- Feb 10 14:50:22 volumio volumio[9639]: info: ----- System startup ---- Feb 10 14:50:22 volumio volumio[9639]: info: ------------------------------------------- Feb 10 14:50:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 119. Feb 10 14:50:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:23 volumio go-librespot[9660]: go-librespot daemon starting... Feb 10 14:50:23 volumio go-librespot[9661]: time="2026-02-10T14:50:23-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:50:23 volumio go-librespot[9661]: time="2026-02-10T14:50:23-06:00" level=debug msg="app state loaded" Feb 10 14:50:23 volumio go-librespot[9661]: time="2026-02-10T14:50:23-06:00" level=debug msg="stored credentials not found" Feb 10 14:50:23 volumio go-librespot[9661]: time="2026-02-10T14:50:23-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:50:23 volumio volumio[9639]: info: MYVOLUMIO Environment detected Feb 10 14:50:23 volumio go-librespot[9661]: time="2026-02-10T14:50:23-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 14:50:23 volumio go-librespot[9661]: time="2026-02-10T14:50:23-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 14:50:23 volumio go-librespot[9661]: time="2026-02-10T14:50:23-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 14:50:23 volumio volumio[9639]: info: Plugin folders cleanup Feb 10 14:50:23 volumio volumio[9639]: info: Scanning into folder /volumio/app/plugins/ Feb 10 14:50:23 volumio volumio[9639]: info: Scanning category audio_interface Feb 10 14:50:23 volumio go-librespot[9661]: time="2026-02-10T14:50:23-06:00" level=info msg="zeroconf server listening on port 39297" Feb 10 14:50:23 volumio volumio[9639]: info: Scanning category miscellanea Feb 10 14:50:23 volumio volumio[9639]: info: Scanning category music_service Feb 10 14:50:23 volumio volumio[9639]: info: Scanning category plugins.json Feb 10 14:50:23 volumio volumio[9639]: info: Scanning category system_controller Feb 10 14:50:23 volumio volumio[9639]: info: Scanning category user_interface Feb 10 14:50:23 volumio volumio[9639]: info: Scanning into folder /data/plugins/ Feb 10 14:50:23 volumio volumio[9639]: info: Scanning category audio_interface Feb 10 14:50:23 volumio volumio[9639]: info: Scanning category music_service Feb 10 14:50:23 volumio volumio[9639]: info: Scanning category system_controller Feb 10 14:50:23 volumio volumio[9639]: info: Scanning category system_hardware Feb 10 14:50:23 volumio volumio[9639]: info: Scanning category user_interface Feb 10 14:50:23 volumio volumio[9639]: info: Plugin folders cleanup completed Feb 10 14:50:23 volumio volumio[9639]: info: ------------------------------------------- Feb 10 14:50:23 volumio volumio[9639]: info: ----- Core plugins startup ---- Feb 10 14:50:23 volumio volumio[9639]: info: ------------------------------------------- Feb 10 14:50:23 volumio volumio[9639]: info: Loading plugins from folder /volumio/app/plugins/ Feb 10 14:50:23 volumio volumio[9639]: info: Adding plugin upnp to MyMusic Plugins Feb 10 14:50:23 volumio volumio[9639]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 10 14:50:23 volumio volumio[9639]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 10 14:50:23 volumio volumio[9639]: info: Loading plugins from folder /data/plugins/ Feb 10 14:50:23 volumio volumio[9639]: info: Loading plugin "system"... Feb 10 14:50:23 volumio volumio[9639]: info: Loading plugin "appearance"... Feb 10 14:50:23 volumio go-librespot[9661]: time="2026-02-10T14:50:23-06:00" level=debug msg="obtained new client token: AAAKA+9fWpjbLEDYq5NdBFjSursCrsSvh1H0AwgUR9c7I5Yz2i6TU+Q7U+8YNO8RRevyFGFzJQGBHtDESGy/uyFiHYRR17B5ltroTf+KIW6H1nRzTaJYcAoElTID6yZGTYrOrXpiU8CruXM+cxrcmCFG0ddq2kiQGRWkbt5JV0gBJkQaz8aeG/TUxok47lRbzsL/mVe7dspbvYUoIp/lwIVFziSH/LbLT/DUWU4Lu1WKe8gTKPxQitVYuw==" Feb 10 14:50:23 volumio go-librespot[9661]: time="2026-02-10T14:50:23-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 14:50:23 volumio go-librespot[9661]: time="2026-02-10T14:50:23-06:00" level=debug msg="completed keyexchange" Feb 10 14:50:23 volumio go-librespot[9661]: time="2026-02-10T14:50:23-06:00" level=debug msg="completed challenge" Feb 10 14:50:23 volumio go-librespot[9661]: time="2026-02-10T14:50:23-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:50:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:50:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:50:24 volumio volumio[9639]: info: Loading plugin "network"... Feb 10 14:50:24 volumio volumio[9639]: info: Refreshing Cached IP Addresses Feb 10 14:50:24 volumio sudo[9675]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 14:50:24 volumio sudo[9675]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:24 volumio sudo[9675]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:24 volumio sudo[9677]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 14:50:24 volumio sudo[9677]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:24 volumio volumio[9639]: info: Loading plugin "services"... Feb 10 14:50:24 volumio sudo[9677]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:24 volumio volumio[9639]: info: Loading plugin "alsa_controller"... Feb 10 14:50:24 volumio sudo[9685]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 10 14:50:24 volumio sudo[9685]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:24 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 14:50:24 volumio volumio[9639]: info: Loading plugin "wizard"... Feb 10 14:50:24 volumio volumio[9639]: info: Loading plugin "networkfs"... Feb 10 14:50:24 volumio volumio[9639]: info: Starting Udev Watcher for removable devices Feb 10 14:50:24 volumio volumio[9639]: info: Ignoring mount for partition: boot Feb 10 14:50:24 volumio volumio[9639]: info: Ignoring mount for partition: volumio Feb 10 14:50:24 volumio volumio[9639]: info: Ignoring mount for partition: volumio_data Feb 10 14:50:24 volumio volumio[9639]: info: Mounting Device Wikipedia Feb 10 14:50:24 volumio sudo[9714]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Feb 10 14:50:24 volumio sudo[9714]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:24 volumio sudo[9714]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:24 volumio volumio[9639]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Feb 10 14:50:24 volumio volumio[9639]: dmesg(1) may have more information after failed mount system call. Feb 10 14:50:24 volumio volumio[9639]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Feb 10 14:50:24 volumio volumio[9639]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Feb 10 14:50:24 volumio volumio[9639]: dmesg(1) may have more information after failed mount system call. Feb 10 14:50:24 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 14:50:24 volumio volumio[9639]: info: Loading plugin "volumio_command_line_client"... Feb 10 14:50:24 volumio volumio[9639]: info: Loading plugin "upnp"... Feb 10 14:50:24 volumio volumio[9639]: info: [1770756624971] Starting Upmpd Daemon Feb 10 14:50:24 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 14:50:24 volumio volumio[9639]: info: Loading plugin "my_music"... Feb 10 14:50:24 volumio volumio[9639]: info: Loading plugin "mpd"... Feb 10 14:50:25 volumio sudo[9685]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:25 volumio volumio-remote-updater[751]: [2026-02-10 14:50:25] [connect] Successful connection Feb 10 14:50:25 volumio volumio[9639]: info: Loading plugin "upnp_browser"... Feb 10 14:50:25 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 10 14:50:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 120. Feb 10 14:50:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:26 volumio go-librespot[9717]: go-librespot daemon starting... Feb 10 14:50:26 volumio go-librespot[9718]: time="2026-02-10T14:50:26-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:50:26 volumio go-librespot[9718]: time="2026-02-10T14:50:26-06:00" level=debug msg="app state loaded" Feb 10 14:50:26 volumio go-librespot[9718]: time="2026-02-10T14:50:26-06:00" level=debug msg="stored credentials not found" Feb 10 14:50:26 volumio go-librespot[9718]: time="2026-02-10T14:50:26-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:50:27 volumio go-librespot[9718]: time="2026-02-10T14:50:27-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 14:50:27 volumio go-librespot[9718]: time="2026-02-10T14:50:27-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 14:50:27 volumio go-librespot[9718]: time="2026-02-10T14:50:27-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 14:50:27 volumio go-librespot[9718]: time="2026-02-10T14:50:27-06:00" level=info msg="zeroconf server listening on port 42307" Feb 10 14:50:27 volumio go-librespot[9718]: time="2026-02-10T14:50:27-06:00" level=debug msg="obtained new client token: AABV0CiSXZOShq3r/XKiJpOxQAfVZFVB/06OzafnFLHpczHHpyWTCS1araVlYkm6crGC4nSVcvC9/Z5ogogPiIURgWqjVroZroQJtNuPteKg5HQwpq9MUjSB2rw0ofHtXzsPeVWLHng3Lqt8Wsk/IVHQ/AHdFmmAnFavnd5qvAkap3xN2Umv5Q+3wmKNAOOnXtlt+p88sm3R5kwvYnJK9y4MUl1SBj6q3eQHR6Lj8iRvmCUuH3J8r31GfA==" Feb 10 14:50:27 volumio go-librespot[9718]: time="2026-02-10T14:50:27-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 14:50:27 volumio go-librespot[9718]: time="2026-02-10T14:50:27-06:00" level=debug msg="completed keyexchange" Feb 10 14:50:27 volumio go-librespot[9718]: time="2026-02-10T14:50:27-06:00" level=debug msg="completed challenge" Feb 10 14:50:27 volumio go-librespot[9718]: time="2026-02-10T14:50:27-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:50:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:50:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:50:28 volumio volumio[9639]: info: Loading plugin "alarm-clock"... Feb 10 14:50:28 volumio volumio[9639]: info: Loading plugin "airplay_emulation"... Feb 10 14:50:28 volumio volumio[9639]: info: Starting Shairport Sync Feb 10 14:50:28 volumio volumio[9639]: info: Loading plugin "last_100"... Feb 10 14:50:28 volumio volumio[9639]: info: Loading plugin "webradio"... Feb 10 14:50:28 volumio volumio[9639]: info: Loading plugin "i2s_dacs"... Feb 10 14:50:28 volumio volumio[9639]: info: I2S DAC not set, start Auto-detection Feb 10 14:50:28 volumio volumio[9639]: info: Loading plugin "volumiodiscovery"... Feb 10 14:50:28 volumio volumio[9639]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 14:50:28 volumio volumio[9639]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 14:50:28 volumio volumio[9639]: *** WARNING *** For more information see Feb 10 14:50:28 volumio volumio[9639]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 14:50:28 volumio volumio[9639]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 14:50:28 volumio volumio[9639]: *** WARNING *** For more information see Feb 10 14:50:28 volumio node[9639]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 14:50:28 volumio node[9639]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 14:50:28 volumio node[9639]: *** WARNING *** For more information see Feb 10 14:50:28 volumio node[9639]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 14:50:28 volumio node[9639]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 14:50:28 volumio node[9639]: *** WARNING *** For more information see Feb 10 14:50:28 volumio volumio[9639]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 10 14:50:28 volumio volumio[9639]: info: Discovery: Started advertising with name: Volumio Feb 10 14:50:28 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 14:50:28 volumio volumio[9639]: info: Loading plugin "bandcamp"... Feb 10 14:50:29 volumio volumio[9639]: info: Plugin calmradio is not enabled Feb 10 14:50:29 volumio volumio[9639]: info: Loading plugin "soundcloud"... Feb 10 14:50:30 volumio kernel: hwmon hwmon1: Voltage normalised Feb 10 14:50:30 volumio volumio[9639]: info: Loading plugin "spop"... Feb 10 14:50:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 121. Feb 10 14:50:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:30 volumio go-librespot[9729]: go-librespot daemon starting... Feb 10 14:50:30 volumio go-librespot[9730]: time="2026-02-10T14:50:30-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:50:30 volumio go-librespot[9730]: time="2026-02-10T14:50:30-06:00" level=debug msg="app state loaded" Feb 10 14:50:30 volumio go-librespot[9730]: time="2026-02-10T14:50:30-06:00" level=debug msg="stored credentials not found" Feb 10 14:50:30 volumio go-librespot[9730]: time="2026-02-10T14:50:30-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:50:31 volumio go-librespot[9730]: time="2026-02-10T14:50:31-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 14:50:31 volumio go-librespot[9730]: time="2026-02-10T14:50:31-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 10 14:50:31 volumio go-librespot[9730]: time="2026-02-10T14:50:31-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 10 14:50:31 volumio go-librespot[9730]: time="2026-02-10T14:50:31-06:00" level=info msg="zeroconf server listening on port 42421" Feb 10 14:50:31 volumio volumio[9639]: info: Loading plugin "squeezelite_mc"... Feb 10 14:50:31 volumio go-librespot[9730]: time="2026-02-10T14:50:31-06:00" level=debug msg="obtained new client token: AABtioiQnhOWBoaUGwYWoLA0Bg4/XNpnTG0bvfo6kMk6qMMaNOGykofTbCgjsQOPUkVzCf4nJM+yAHxTA3ZYkPxo1LmxIs8/hB3w1VYyCY57k90YaZnAYd6yOEuk7/9LEX0D9KPh6uqY1/VeV3aLwLy2fyJ/H3QhJ52YZJzBiU7Msd9x4COcgv5VBggVDp0CGuRzZlWBAZuRhWcFWWlBxQ+Bd9yLsSgEkdIxK8r+yl6XeQWx7fUoIC2cMA==" Feb 10 14:50:31 volumio go-librespot[9730]: time="2026-02-10T14:50:31-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Feb 10 14:50:31 volumio go-librespot[9730]: time="2026-02-10T14:50:31-06:00" level=debug msg="connected to ap-guc3.spotify.com:443" Feb 10 14:50:31 volumio go-librespot[9730]: time="2026-02-10T14:50:31-06:00" level=debug msg="completed keyexchange" Feb 10 14:50:31 volumio go-librespot[9730]: time="2026-02-10T14:50:31-06:00" level=debug msg="completed challenge" Feb 10 14:50:31 volumio go-librespot[9730]: time="2026-02-10T14:50:31-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:50:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:50:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:50:31 volumio volumio[9639]: info: Loading plugin "youtube2"... Feb 10 14:50:32 volumio volumio[9639]: info: Loading plugin "ytcr"... Feb 10 14:50:33 volumio volumio[9639]: info: Loading plugin "ytmusic"... Feb 10 14:50:34 volumio volumio[9639]: info: Plugin now_playing is not enabled Feb 10 14:50:34 volumio volumio[9639]: info: Loading plugin "outputs"... Feb 10 14:50:34 volumio volumio[9639]: info: Loading plugin "albumart"... Feb 10 14:50:34 volumio volumio[9639]: info: Plugin example_plugin is not enabled Feb 10 14:50:34 volumio volumio[9639]: info: Loading plugin "inputs"... Feb 10 14:50:34 volumio volumio[9639]: info: Loading plugin "updater_comm"... Feb 10 14:50:34 volumio volumio[9639]: info: Plugin mpdemulation is not enabled Feb 10 14:50:34 volumio volumio[9639]: info: Loading plugin "rest_api"... Feb 10 14:50:34 volumio volumio[9639]: info: Loading plugin "websocket"... Feb 10 14:50:34 volumio volumio[9639]: info: Starting Socket.io Server version 1.7.4 Feb 10 14:50:34 volumio volumio[9639]: info: Plugin fusiondsp is not enabled Feb 10 14:50:34 volumio volumio[9639]: info: Plugin mpdoutput is not enabled Feb 10 14:50:34 volumio volumio[9639]: info: Plugin RoonBridge is not enabled Feb 10 14:50:34 volumio volumio[9639]: info: Loading plugin "podcast"... Feb 10 14:50:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 122. Feb 10 14:50:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:34 volumio go-librespot[9764]: go-librespot daemon starting... Feb 10 14:50:34 volumio go-librespot[9765]: time="2026-02-10T14:50:34-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:50:34 volumio go-librespot[9765]: time="2026-02-10T14:50:34-06:00" level=debug msg="app state loaded" Feb 10 14:50:34 volumio go-librespot[9765]: time="2026-02-10T14:50:34-06:00" level=debug msg="stored credentials not found" Feb 10 14:50:34 volumio go-librespot[9765]: time="2026-02-10T14:50:34-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:50:34 volumio volumio[9639]: info: ControllerPodcast::constructor Feb 10 14:50:35 volumio volumio[9639]: info: Loading plugin "volusonic"... Feb 10 14:50:35 volumio volumio[9740]: Forking 3 albumart workers Feb 10 14:50:35 volumio go-librespot[9765]: time="2026-02-10T14:50:35-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 14:50:35 volumio go-librespot[9765]: time="2026-02-10T14:50:35-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 14:50:35 volumio go-librespot[9765]: time="2026-02-10T14:50:35-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 14:50:35 volumio go-librespot[9765]: time="2026-02-10T14:50:35-06:00" level=info msg="zeroconf server listening on port 43703" Feb 10 14:50:35 volumio go-librespot[9765]: time="2026-02-10T14:50:35-06:00" level=debug msg="obtained new client token: AABN3Wr3ZhUMF7rU+fTOealyIjHt75D87NKDTQDfkPgGFkQdpENznW8Tk6SaQmC5ddI9uutbtBuoGeRFDg8p1a7M3F0nxRUBxXW52BpPA+s5ojOcieCx8FO0LM9sgI2XbNAWt61NcyjV5mHd/ZnES89J7Tuf2UTwR7+ZSqp2JmTqPxMXN2hV1v6ErU1V9MxnkV4nLQf+q2CE1B98HKoXCFcJwa+IL7QGyDpjIBdxaqHPv3FQTaTLyq7tAw==" Feb 10 14:50:35 volumio go-librespot[9765]: time="2026-02-10T14:50:35-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 14:50:35 volumio go-librespot[9765]: time="2026-02-10T14:50:35-06:00" level=debug msg="completed keyexchange" Feb 10 14:50:35 volumio go-librespot[9765]: time="2026-02-10T14:50:35-06:00" level=debug msg="completed challenge" Feb 10 14:50:35 volumio go-librespot[9765]: time="2026-02-10T14:50:35-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:50:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:50:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:50:36 volumio volumio[9639]: info: Applying required configuration parameters for plugin volusonic Feb 10 14:50:36 volumio volumio[9639]: info: Loading plugin "backup_restore"... Feb 10 14:50:36 volumio volumio[9774]: Starting albumart workers Feb 10 14:50:36 volumio volumio[9773]: Starting albumart workers Feb 10 14:50:36 volumio volumio[9772]: Starting albumart workers Feb 10 14:50:36 volumio volumio[9639]: info: Applying required configuration parameters for plugin backup_restore Feb 10 14:50:36 volumio volumio[9639]: info: Plugin rpi_eeprom_config is not enabled Feb 10 14:50:36 volumio volumio[9639]: info: Plugin rpi_eeprom_updater is not enabled Feb 10 14:50:36 volumio volumio[9639]: info: Loading plugin "scheduledrestart"... Feb 10 14:50:37 volumio volumio[9639]: info: Applying required configuration parameters for plugin scheduledrestart Feb 10 14:50:37 volumio volumio[9639]: info: Plugin Bluetoothremote is not enabled Feb 10 14:50:37 volumio volumio[9639]: info: Plugin music_services_shield is not enabled Feb 10 14:50:37 volumio volumio[9639]: info: Loading plugin "Systeminfo"... Feb 10 14:50:37 volumio volumio-remote-updater[751]: [2026-02-10 14:50:37] [connect] Successful connection Feb 10 14:50:37 volumio volumio[9639]: info: Plugin peppymeterbasic is not enabled Feb 10 14:50:37 volumio volumio[9639]: info: Loading plugin "peppyspectrum"... Feb 10 14:50:38 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 10 14:50:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 123. Feb 10 14:50:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:38 volumio go-librespot[9822]: go-librespot daemon starting... Feb 10 14:50:38 volumio volumio[9639]: info: Loading i18n strings for locale en Feb 10 14:50:38 volumio volumio[9639]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 10 14:50:38 volumio go-librespot[9823]: time="2026-02-10T14:50:38-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:50:38 volumio go-librespot[9823]: time="2026-02-10T14:50:38-06:00" level=debug msg="app state loaded" Feb 10 14:50:38 volumio go-librespot[9823]: time="2026-02-10T14:50:38-06:00" level=debug msg="stored credentials not found" Feb 10 14:50:38 volumio volumio[9639]: Updating browse sources language Feb 10 14:50:38 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:50:38 volumio go-librespot[9823]: time="2026-02-10T14:50:38-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:50:38 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 14:50:38 volumio volumio[9639]: info: CoreCommandRouter::initPlayerControls Feb 10 14:50:38 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:38 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:38 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:38 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:38 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:38 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:38 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:38 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:38 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 14:50:38 volumio volumio[9639]: Express server listening on port 3000 Feb 10 14:50:38 volumio volumio[9639]: [Metrics] WebUI: 16s 929.40ms Feb 10 14:50:38 volumio volumio[9639]: info: CoreStateMachine::resetVolumioState Feb 10 14:50:38 volumio volumio[9639]: info: CoreStateMachine::getcurrentVolume Feb 10 14:50:38 volumio volumio[9639]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 14:50:39 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 14:50:39 volumio sudo[9835]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 14:50:39 volumio sudo[9835]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:39 volumio go-librespot[9823]: time="2026-02-10T14:50:39-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 14:50:39 volumio go-librespot[9823]: time="2026-02-10T14:50:39-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 10 14:50:39 volumio go-librespot[9823]: time="2026-02-10T14:50:39-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 10 14:50:39 volumio sudo[9835]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:39 volumio sudo[9837]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 14:50:39 volumio sudo[9837]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:39 volumio go-librespot[9823]: time="2026-02-10T14:50:39-06:00" level=info msg="zeroconf server listening on port 40201" Feb 10 14:50:39 volumio sudo[9837]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:39 volumio volumio[9639]: info: Volumio Network Manager: Network status updated: 1 Feb 10 14:50:39 volumio go-librespot[9823]: time="2026-02-10T14:50:39-06:00" level=debug msg="obtained new client token: AAC2D1IQxUG9ic1HCHpOO7LBjioe/yBzTw88QgdIpjIY3lfp/yuz1O9DIKJlQFvmWk443TFbyOBLcDw4YJMEjaW5POyOjoei3453zCDqr4c1eDFELLdFjh0cQaG8H/hrEkRlVNVjP7qQpC+KSFwFtg0VzWrzqkw3D6zMMpaTpu4XVcrb3j54hgihixWKPTAaT80+USS4rnIMC+U4gAcv04XvoJhG4MNDTv8RCpeIPnkhVFB4SMSaT5I=" Feb 10 14:50:39 volumio go-librespot[9823]: time="2026-02-10T14:50:39-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Feb 10 14:50:39 volumio volumio[9639]: info: VolumeController:: Volume=100 Mute =false Feb 10 14:50:39 volumio volumio[9639]: info: CoreStateMachine::pushState Feb 10 14:50:39 volumio go-librespot[9823]: time="2026-02-10T14:50:39-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:443, retrying with a different AP" error="dial tcp 104.154.127.247:443: connect: connection refused" Feb 10 14:50:39 volumio volumio[9639]: info: CorePlayQueue::getTrack 0 Feb 10 14:50:39 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 14:50:39 volumio volumio[9639]: info: CoreCommandRouter::volumioPushState Feb 10 14:50:39 volumio volumio[9639]: info: CoreStateMachine::updateTrackBlock Feb 10 14:50:39 volumio volumio[9639]: info: CorePlayQueue::getTrackBlock Feb 10 14:50:39 volumio volumio[9639]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 14:50:39 volumio go-librespot[9823]: time="2026-02-10T14:50:39-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:80, retrying with a different AP" error="dial tcp 104.154.127.247:80: connect: connection refused" Feb 10 14:50:39 volumio volumio-remote-updater[751]: [2026-02-10 14:50:39] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770756637 101 Feb 10 14:50:39 volumio volumio[9639]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 10 14:50:39 volumio volumio[9639]: info: Reloading queue from file Feb 10 14:50:39 volumio volumio[9639]: info: CoreStateMachine::setRepeat null single undefined Feb 10 14:50:39 volumio volumio[9639]: info: CoreStateMachine::pushState Feb 10 14:50:39 volumio volumio[9639]: info: CorePlayQueue::getTrack 0 Feb 10 14:50:39 volumio volumio[9639]: info: CoreCommandRouter::volumioPushState Feb 10 14:50:39 volumio volumio[9639]: info: CoreStateMachine::setRandom null Feb 10 14:50:39 volumio volumio[9639]: info: CoreStateMachine::pushState Feb 10 14:50:39 volumio volumio[9639]: info: CorePlayQueue::getTrack 0 Feb 10 14:50:39 volumio volumio[9639]: info: CoreCommandRouter::volumioPushState Feb 10 14:50:39 volumio volumio[9639]: info: Setting Device type: Raspberry PI Feb 10 14:50:39 volumio go-librespot[9823]: time="2026-02-10T14:50:39-06:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 14:50:39 volumio volumio[9639]: info: VolumeController:: Volume=100 Mute =false Feb 10 14:50:39 volumio volumio[9639]: info: CoreStateMachine::pushState Feb 10 14:50:39 volumio volumio[9639]: info: CorePlayQueue::getTrack 0 Feb 10 14:50:39 volumio volumio[9639]: info: CoreCommandRouter::volumioPushState Feb 10 14:50:39 volumio volumio[9639]: info: Completed loading Core Plugins Feb 10 14:50:39 volumio volumio[9639]: info: Preparing to generate the ALSA configuration file Feb 10 14:50:39 volumio sudo[9850]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 10 14:50:39 volumio sudo[9850]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:39 volumio volumio[9639]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Feb 10 14:50:39 volumio volumio[9639]: info: Discovery: Found device Volumio Feb 10 14:50:39 volumio volumio[9639]: info: CoreCommandRouter::volumioGetState Feb 10 14:50:39 volumio volumio[9639]: info: CorePlayQueue::getTrack 0 Feb 10 14:50:39 volumio volumio[9639]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Feb 10 14:50:39 volumio volumio[9639]: info: Discovery: Found device Volumio Feb 10 14:50:39 volumio volumio[9639]: info: CoreCommandRouter::volumioGetState Feb 10 14:50:39 volumio volumio[9639]: info: CorePlayQueue::getTrack 0 Feb 10 14:50:39 volumio volumio[9639]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 10 14:50:39 volumio volumio[9639]: info: Reading ALSA contributions from plugins. Feb 10 14:50:39 volumio volumio[9639]: info: Asound.conf file unchanged, so no further update is needed Feb 10 14:50:39 volumio volumio[9639]: info: Output device has changed, restarting MPD Feb 10 14:50:39 volumio go-librespot[9823]: time="2026-02-10T14:50:39-06:00" level=debug msg="completed keyexchange" Feb 10 14:50:39 volumio go-librespot[9823]: time="2026-02-10T14:50:39-06:00" level=debug msg="completed challenge" Feb 10 14:50:39 volumio sudo[9850]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:39 volumio volumio[9639]: info: Output device has changed, restarting Shairport Sync Feb 10 14:50:39 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:39 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 14:50:39 volumio sudo[9853]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 14:50:39 volumio sudo[9853]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:39 volumio sudo[9855]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 14:50:39 volumio sudo[9855]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:39 volumio sudo[9853]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:39 volumio volumio[9639]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 14:50:39 volumio volumio[9639]: info: ___________ START PLUGINS ___________ Feb 10 14:50:39 volumio volumio[9639]: info: ControllerMpd::onStart: Initializing MPD Feb 10 14:50:39 volumio volumio[9639]: info: Creating MPD Configuration file Feb 10 14:50:39 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 14:50:39 volumio volumio[9639]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 14:50:39 volumio volumio[9639]: info: [1770756639984] CoreMusicLibrary::Adding element Media Servers Feb 10 14:50:39 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:50:40 volumio sudo[9863]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 14:50:40 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 10 14:50:40 volumio sudo[9863]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:40 volumio go-librespot[9823]: time="2026-02-10T14:50:40-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:50:40 volumio sudo[9863]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:50:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:50:40 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:40 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 14:50:40 volumio sudo[9865]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 14:50:40 volumio sudo[9865]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:40 volumio volumio[9639]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 14:50:40 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:40 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 14:50:40 volumio volumio[9639]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 14:50:40 volumio volumio[9639]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 14:50:40 volumio volumio[9639]: info: [1770756640188] CoreMusicLibrary::Adding element Last_100 Feb 10 14:50:40 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:50:40 volumio volumio[9639]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 14:50:40 volumio volumio[9639]: info: [1770756640196] CoreMusicLibrary::Adding element Webradio Feb 10 14:50:40 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:50:40 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 14:50:40 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 14:50:40 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 14:50:40 volumio systemd[1]: mpd.service: Consumed 4.106s CPU time. Feb 10 14:50:40 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 14:50:40 volumio volumio[9639]: info: Initializing BBC Radios Feb 10 14:50:40 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 14:50:40 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 14:50:40 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 14:50:40 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 14:50:40 volumio volumio[9639]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 14:50:40 volumio volumio[9639]: info: [1770756640289] CoreMusicLibrary::Adding element Bandcamp Discover Feb 10 14:50:40 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source Bandcamp Discover Feb 10 14:50:40 volumio volumio[9639]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 14:50:40 volumio volumio[9639]: info: [1770756640300] CoreMusicLibrary::Adding element SoundCloud Feb 10 14:50:40 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source Bandcamp Discover Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source SoundCloud Feb 10 14:50:40 volumio volumio[9639]: info: Creating Spotify config file Feb 10 14:50:40 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 14:50:40 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:40 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 14:50:40 volumio sudo[9891]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 10 14:50:40 volumio sudo[9891]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 10 14:50:40 volumio sudo[9891]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:40 volumio volumio[9639]: info: [squeezelite_mc] Starting proxy server... Feb 10 14:50:40 volumio volumio[9639]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 14:50:40 volumio volumio[9639]: info: [1770756640673] CoreMusicLibrary::Adding element YouTube2 Feb 10 14:50:40 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source Bandcamp Discover Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source SoundCloud Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source YouTube2 Feb 10 14:50:40 volumio volumio[9639]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 14:50:40 volumio volumio[9639]: info: [1770756640694] CoreMusicLibrary::Adding element YouTube Music Feb 10 14:50:40 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source Bandcamp Discover Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source SoundCloud Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source YouTube2 Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source YouTube Music Feb 10 14:50:40 volumio volumio[9639]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 14:50:40 volumio volumio[9639]: info: [1770756640707] CoreMusicLibrary::Adding element Podcast Feb 10 14:50:40 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source Bandcamp Discover Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source SoundCloud Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source YouTube2 Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source YouTube Music Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source Podcast Feb 10 14:50:40 volumio volumio[9639]: info: Loading i18n strings for locale en Feb 10 14:50:40 volumio volumio[9639]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 10 14:50:40 volumio volumio[9639]: Updating browse sources language Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source Bandcamp Discover Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source SoundCloud Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source YouTube2 Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source YouTube Music Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source Podcast Feb 10 14:50:40 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source Bandcamp Discover Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source SoundCloud Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source YouTube2 Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source YouTube Music Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source Podcast Feb 10 14:50:40 volumio volumio[9639]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 14:50:40 volumio volumio[9639]: info: [1770756640755] CoreMusicLibrary::Adding element Volusonic Feb 10 14:50:40 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source Bandcamp Discover Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source SoundCloud Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source YouTube2 Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source YouTube Music Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source Podcast Feb 10 14:50:40 volumio volumio[9639]: Cannot find translation for source Volusonic Feb 10 14:50:40 volumio volumio[9639]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Feb 10 14:50:40 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Feb 10 14:50:40 volumio volumio[9639]: info: Volumio Calling Home Feb 10 14:50:40 volumio volumio[9639]: info: [squeezelite_mc] Proxy server started on port 35125 Feb 10 14:50:40 volumio volumio[9639]: info: Preparing to generate the ALSA configuration file Feb 10 14:50:40 volumio volumio[9639]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 14:50:41 volumio volumio[9639]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 10 14:50:41 volumio volumio[9639]: info: Reading ALSA contributions from plugins. Feb 10 14:50:41 volumio volumio[9639]: info: MPD Permissions set Feb 10 14:50:41 volumio volumio[9639]: info: MPD Permissions set Feb 10 14:50:41 volumio volumio[9639]: info: Upmpdcli Daemon Started Feb 10 14:50:41 volumio volumio[9639]: info: Spotify config file written Feb 10 14:50:41 volumio sudo[9901]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 10 14:50:41 volumio sudo[9901]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:41 volumio volumio[9639]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 10 14:50:41 volumio volumio[9639]: info: VolumeController:: Volume=100 Mute =false Feb 10 14:50:41 volumio volumio[9639]: info: CoreStateMachine::pushState Feb 10 14:50:41 volumio volumio[9639]: info: CorePlayQueue::getTrack 0 Feb 10 14:50:41 volumio volumio[9639]: info: CoreCommandRouter::volumioPushState Feb 10 14:50:41 volumio volumio[9639]: info: [squeezelite_mc] Server discovery started Feb 10 14:50:41 volumio volumio[9639]: info: [squeezelite_mc] Player finder started Feb 10 14:50:41 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:41 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:41 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:41 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 14:50:41 volumio volumio[9639]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Feb 10 14:50:41 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:41 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:41 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:41 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:41 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:41 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:41 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:41 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:41 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 14:50:41 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:41 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:41 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:41 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:41 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:41 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:41 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:41 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:41 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:41 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 14:50:41 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:41 volumio volumio[9639]: info: No need to fix Spotify hosts Feb 10 14:50:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:41 volumio go-librespot[9908]: go-librespot daemon starting... Feb 10 14:50:41 volumio sudo[9901]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:41 volumio go-librespot[9917]: time="2026-02-10T14:50:41-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:50:41 volumio go-librespot[9917]: time="2026-02-10T14:50:41-06:00" level=debug msg="app state loaded" Feb 10 14:50:41 volumio go-librespot[9917]: time="2026-02-10T14:50:41-06:00" level=debug msg="stored credentials not found" Feb 10 14:50:41 volumio go-librespot[9917]: time="2026-02-10T14:50:41-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:50:41 volumio volumio[9639]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 10 14:50:41 volumio volumio[9639]: info: Volumio called home Feb 10 14:50:41 volumio volumio[9639]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Feb 10 14:50:41 volumio volumio[9639]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Feb 10 14:50:41 volumio volumio[9639]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Feb 10 14:50:41 volumio sudo[9926]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Feb 10 14:50:41 volumio sudo[9926]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:41 volumio sudo[9926]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:41 volumio go-librespot[9917]: time="2026-02-10T14:50:41-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 14:50:41 volumio go-librespot[9917]: time="2026-02-10T14:50:41-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 10 14:50:41 volumio go-librespot[9917]: time="2026-02-10T14:50:41-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 10 14:50:41 volumio volumio[9639]: info: Starting Shairport Sync Feb 10 14:50:41 volumio volumio[9639]: info: Starting Shairport Sync Feb 10 14:50:41 volumio go-librespot[9917]: time="2026-02-10T14:50:41-06:00" level=info msg="zeroconf server listening on port 33915" Feb 10 14:50:41 volumio volumio[9639]: info: Starting Shairport Sync Feb 10 14:50:41 volumio sudo[9929]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 14:50:41 volumio sudo[9929]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:41 volumio sudo[9931]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 14:50:41 volumio sudo[9931]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:41 volumio volumio[9639]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 14:50:41 volumio volumio[9639]: SPOTIFY: BQDCUawQtSNO3JmxVwQbRaFzEZ6-4d4R4MAz8eT4qZeyo3iJj1t9H_bnGa3CSHiXhp-JUDw2fVDPPrTCgu8ihAF2Bhkn1s7duaTwI78D4foL2h6QkUn_xPMACNmuV75jaHU3LIq5b9AIOuPSpfkl0hEZ1DcWXDgJpk7Ua8uhwLgCvcG8nWB1a7WQLAbbpa3o0H6Jz08sL32UDHdnAmamjB-G4Z7K8BdJwt_WI8Y Feb 10 14:50:41 volumio volumio[9639]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 14:50:41 volumio volumio[9639]: info: New Spotify access token = BQDCUawQtSNO3JmxVwQbRaFzEZ6-4d4R4MAz8eT4qZeyo3iJj1t9H_bnGa3CSHiXhp-JUDw2fVDPPrTCgu8ihAF2Bhkn1s7duaTwI78D4foL2h6QkUn_xPMACNmuV75jaHU3LIq5b9AIOuPSpfkl0hEZ1DcWXDgJpk7Ua8uhwLgCvcG8nWB1a7WQLAbbpa3o0H6Jz08sL32UDHdnAmamjB-G4Z7K8BdJwt_WI8Y Feb 10 14:50:41 volumio volumio[9639]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 10 14:50:41 volumio sudo[9933]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 14:50:41 volumio sudo[9933]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:41 volumio go-librespot[9917]: time="2026-02-10T14:50:41-06:00" level=debug msg="obtained new client token: AAC2rDIrh0cOzIc63GyW/lyDM6+ZhaquObraqAVUVcuF7eDBLYgFKjvWSi+FRHEgy6Ew7i3m0EsZKm3nXPuHv7iJZWJqVOZ7xMHn7QjjuLdd4B7kKGFiDrosnOQF7Peg6v1ny7coYARKojkrmcsd/TmQ0ZtBCgMoGGZQ9FwSDg3ZDdm8HM+kWmfZQ6c2hdgZ+uCbkm8ocWsOfxfzMNn0XsT2pixtK9S/SYOdZiJZPO+vhrbTPN/gHUm6YA==" Feb 10 14:50:41 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 14:50:41 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 14:50:41 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 14:50:41 volumio systemd[1]: shairport-sync.service: Consumed 2.251s CPU time. Feb 10 14:50:41 volumio volumio[9639]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Feb 10 14:50:41 volumio go-librespot[9917]: time="2026-02-10T14:50:41-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 14:50:41 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 14:50:41 volumio sudo[9931]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:41 volumio go-librespot[9917]: time="2026-02-10T14:50:41-06:00" level=debug msg="completed keyexchange" Feb 10 14:50:41 volumio go-librespot[9917]: time="2026-02-10T14:50:41-06:00" level=debug msg="completed challenge" Feb 10 14:50:41 volumio sudo[9933]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:41 volumio sudo[9940]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Feb 10 14:50:41 volumio sudo[9940]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:41 volumio volumio[9639]: info: Asound.conf file unchanged, so no further update is needed Feb 10 14:50:41 volumio volumio[9639]: info: Output device has changed, restarting MPD Feb 10 14:50:41 volumio sudo[9929]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:41 volumio sudo[9940]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:41 volumio go-librespot[9917]: time="2026-02-10T14:50:41-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:50:41 volumio volumio[9639]: info: Output device has changed, restarting Shairport Sync Feb 10 14:50:41 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:41 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 14:50:41 volumio sudo[9944]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 14:50:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:50:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:50:41 volumio sudo[9944]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:41 volumio sudo[9944]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:42 volumio sudo[9956]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 14:50:42 volumio sudo[9956]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:42 volumio volumio[9639]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 14:50:42 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 14:50:42 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 14:50:42 volumio systemd[1]: mpd.service: Consumed 1.575s CPU time. Feb 10 14:50:42 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 14:50:42 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 14:50:42 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 14:50:42 volumio volumio[9639]: info: Shairport-Sync Started Feb 10 14:50:42 volumio volumio[9639]: Error adding Membership: Error: addMembership EINVAL Feb 10 14:50:42 volumio volumio[9639]: info: Shairport-Sync Started Feb 10 14:50:42 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 14:50:42 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 14:50:42 volumio volumio[9639]: info: MPD Permissions set Feb 10 14:50:42 volumio volumio[9639]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Feb 10 14:50:42 volumio volumio[9639]: info: Shairport-Sync Started Feb 10 14:50:42 volumio sudo[9974]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Feb 10 14:50:42 volumio sudo[9974]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:42 volumio sudo[9974]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:42 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:42 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:42 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:42 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:42 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:42 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:42 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:42 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:42 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 14:50:42 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:42 volumio volumio[9639]: info: CoreCommandRouter::volumioGetState Feb 10 14:50:42 volumio volumio[9639]: info: CorePlayQueue::getTrack 0 Feb 10 14:50:42 volumio volumio[9639]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Feb 10 14:50:42 volumio volumio[9639]: info: Starting Shairport Sync Feb 10 14:50:42 volumio sudo[9982]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Feb 10 14:50:42 volumio sudo[9982]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:42 volumio volumio[9639]: SPOTIFY: User informations: {"display_name":"Clint Smith","external_urls":{"spotify":"https://open.spotify.com/user/clintsmith1"},"followers":{"href":null,"total":7},"href":"https://api.spotify.com/v1/users/clintsmith1","id":"clintsmith1","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee856520409d25d9cc210472a0fd","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b826520409d25d9cc210472a0fd","width":64}],"type":"user","uri":"spotify:user:clintsmith1"} Feb 10 14:50:42 volumio volumio[9639]: info: Spotify Successfully logged in Feb 10 14:50:42 volumio volumio[9639]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 14:50:42 volumio volumio[9639]: info: [1770756642442] CoreMusicLibrary::Adding element Spotify Feb 10 14:50:42 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:50:42 volumio volumio[9639]: Cannot find translation for source Bandcamp Discover Feb 10 14:50:42 volumio volumio[9639]: Cannot find translation for source SoundCloud Feb 10 14:50:42 volumio volumio[9639]: Cannot find translation for source YouTube2 Feb 10 14:50:42 volumio volumio[9639]: Cannot find translation for source YouTube Music Feb 10 14:50:42 volumio volumio[9639]: Cannot find translation for source Podcast Feb 10 14:50:42 volumio volumio[9639]: Cannot find translation for source Volusonic Feb 10 14:50:42 volumio volumio[9639]: Cannot find translation for source Spotify Feb 10 14:50:42 volumio systemd[1]: Reloading. Feb 10 14:50:42 volumio sudo[9971]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 10 14:50:42 volumio sudo[9971]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 10 14:50:42 volumio sudo[9971]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:42 volumio sudo[9984]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 14:50:42 volumio sudo[9984]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:42 volumio kernel: hwmon hwmon1: Voltage normalised Feb 10 14:50:43 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:43 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:43 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:50:43 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 14:50:43 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 10 14:50:43 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 10 14:50:44 volumio sudo[9982]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:44 volumio volumio[9639]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 14:50:44 volumio sudo[10008]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 14:50:44 volumio sudo[10008]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:44 volumio sudo[10008]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:44 volumio volumio[9639]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Feb 10 14:50:44 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 14:50:44 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 14:50:44 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 14:50:44 volumio systemd[1]: shairport-sync.service: Consumed 1.495s CPU time. Feb 10 14:50:44 volumio sudo[10012]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Feb 10 14:50:44 volumio sudo[10012]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:44 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 14:50:44 volumio sudo[9984]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:44 volumio volumio[9639]: info: Shairport-Sync Started Feb 10 14:50:44 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 10 14:50:44 volumio volumio[9639]: info: go-librespot daemon successfully initialized Feb 10 14:50:44 volumio systemd[1]: squeezelite.service: Deactivated successfully. Feb 10 14:50:44 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 10 14:50:44 volumio sudo[10012]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124. Feb 10 14:50:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:45 volumio go-librespot[10043]: go-librespot daemon starting... Feb 10 14:50:45 volumio go-librespot[10044]: time="2026-02-10T14:50:45-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:50:45 volumio go-librespot[10044]: time="2026-02-10T14:50:45-06:00" level=debug msg="app state loaded" Feb 10 14:50:45 volumio go-librespot[10044]: time="2026-02-10T14:50:45-06:00" level=debug msg="stored credentials not found" Feb 10 14:50:45 volumio go-librespot[10044]: time="2026-02-10T14:50:45-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:50:45 volumio volumio[9639]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 14:50:45 volumio sudo[10050]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 14:50:45 volumio sudo[10050]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:45 volumio sudo[10050]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:45 volumio volumio[9639]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Feb 10 14:50:45 volumio sudo[10055]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Feb 10 14:50:45 volumio sudo[10055]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:45 volumio sudo[10055]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:45 volumio volumio[9639]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Feb 10 14:50:45 volumio sudo[10059]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Feb 10 14:50:45 volumio sudo[10059]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:45 volumio go-librespot[10044]: time="2026-02-10T14:50:45-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 14:50:45 volumio go-librespot[10044]: time="2026-02-10T14:50:45-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 14:50:45 volumio go-librespot[10044]: time="2026-02-10T14:50:45-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 14:50:45 volumio go-librespot[10044]: time="2026-02-10T14:50:45-06:00" level=info msg="zeroconf server listening on port 37319" Feb 10 14:50:45 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 10 14:50:45 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 10 14:50:45 volumio sudo[10059]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:45 volumio go-librespot[10044]: time="2026-02-10T14:50:45-06:00" level=debug msg="obtained new client token: AAD13T7NBwefHQCZXfzkhQ4fjLTpx7FjZGHJbbSDWLQ6vbCVMqpDvm5JKtulCHDOrcgmuxKZfVi2b5PCevd7sTr2Jr3qeANIp9fYWJa8VfDMz5piHwTq9TwclrerMhyKxPUA2M5saY4hylI9ziV1dvINcHrXoB3+yY6ZGD/1AKIyh4DgzI4Q3/LpKu7PsGiCeh9PPi5KU2SqgsFIhn5pqie2qTSTgSdcCQAwToXDSpZZwNyD8lP/FcKrNw==" Feb 10 14:50:45 volumio go-librespot[10044]: time="2026-02-10T14:50:45-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 14:50:45 volumio go-librespot[10044]: time="2026-02-10T14:50:45-06:00" level=debug msg="completed keyexchange" Feb 10 14:50:45 volumio go-librespot[10044]: time="2026-02-10T14:50:45-06:00" level=debug msg="completed challenge" Feb 10 14:50:45 volumio go-librespot[10044]: time="2026-02-10T14:50:45-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:50:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:50:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:50:46 volumio volumio[9639]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 14:50:46 volumio sudo[10066]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 14:50:46 volumio sudo[10066]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:46 volumio sudo[10066]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:46 volumio volumio[9639]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 14:50:46 volumio sudo[10069]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 14:50:46 volumio sudo[10069]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:46 volumio sudo[10069]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:47 volumio volumio[9639]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 14:50:47 volumio sudo[10072]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 14:50:47 volumio sudo[10072]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:47 volumio sudo[10072]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:47 volumio mpd[10006]: 2026-02-10T14:50:47 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 10 14:50:47 volumio volumio[9639]: info: Initializing connection to go-librespot Websocket Feb 10 14:50:47 volumio volumio[9639]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 14:50:47 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 10 14:50:47 volumio sudo[9956]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:47 volumio sudo[9865]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:47 volumio sudo[9855]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:47 volumio volumio[9639]: error: MPD error: The expression evaluated to a falsy value: Feb 10 14:50:47 volumio volumio[9639]: assert.ok(self.idling) Feb 10 14:50:47 volumio volumio[9639]: error: The expression evaluated to a falsy value: Feb 10 14:50:47 volumio volumio[9639]: assert.ok(self.idling) Feb 10 14:50:47 volumio volumio[9639]: error: MPD error: The expression evaluated to a falsy value: Feb 10 14:50:47 volumio volumio[9639]: assert.ok(self.idling) Feb 10 14:50:47 volumio volumio[9639]: error: The expression evaluated to a falsy value: Feb 10 14:50:47 volumio volumio[9639]: assert.ok(self.idling) Feb 10 14:50:47 volumio volumio[9639]: info: MPD running with PID10006 Feb 10 14:50:47 volumio volumio[9639]: ,establishing connection Feb 10 14:50:47 volumio volumio[9639]: error: updateQueue error: null Feb 10 14:50:47 volumio volumio[9639]: error: updateQueue error: null Feb 10 14:50:47 volumio volumio[9639]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 14:50:47 volumio sudo[10079]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 14:50:47 volumio sudo[10079]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:47 volumio sudo[10079]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:48 volumio volumio[9639]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 14:50:48 volumio sudo[10082]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 14:50:48 volumio sudo[10082]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:48 volumio sudo[10082]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:48 volumio volumio[9639]: info: Completed starting Core Plugins Feb 10 14:50:48 volumio volumio[9639]: info: ------------------------------------------- Feb 10 14:50:48 volumio volumio[9639]: info: ----- MyVolumio plugins startup ---- Feb 10 14:50:48 volumio volumio[9639]: info: ------------------------------------------- Feb 10 14:50:48 volumio volumio[9639]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 10 14:50:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 125. Feb 10 14:50:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:49 volumio go-librespot[10084]: go-librespot daemon starting... Feb 10 14:50:49 volumio go-librespot[10085]: time="2026-02-10T14:50:49-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:50:49 volumio go-librespot[10085]: time="2026-02-10T14:50:49-06:00" level=debug msg="app state loaded" Feb 10 14:50:49 volumio go-librespot[10085]: time="2026-02-10T14:50:49-06:00" level=debug msg="stored credentials not found" Feb 10 14:50:49 volumio go-librespot[10085]: time="2026-02-10T14:50:49-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:50:49 volumio go-librespot[10085]: time="2026-02-10T14:50:49-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 14:50:49 volumio go-librespot[10085]: time="2026-02-10T14:50:49-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 14:50:49 volumio go-librespot[10085]: time="2026-02-10T14:50:49-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 14:50:49 volumio go-librespot[10085]: time="2026-02-10T14:50:49-06:00" level=info msg="zeroconf server listening on port 35089" Feb 10 14:50:49 volumio go-librespot[10085]: time="2026-02-10T14:50:49-06:00" level=debug msg="obtained new client token: AACut5By7lvIKY3IUqCESuxJfrNZ3Tpw0wMyobTkuG3g5HUfLlybnAuoMgx1RJ0UCOTZ5PnBJorsRvceYYKxdzS3ak1NfPEdftdLqhX1F7LuvxaHBFFSOY3OdnewJZkBCVVxWcntHOB9RwLeQOXc1AGw+Qq10HcU9CZfJ685GDGKpi/tzJeQsaXnPdUUzWp9biP0IQ5xwY05ZpqyUrCgd8OWiPiuk0gyeJynCCWHoHjJEZPn9qwYYI6REQ==" Feb 10 14:50:49 volumio go-librespot[10085]: time="2026-02-10T14:50:49-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 14:50:49 volumio go-librespot[10085]: time="2026-02-10T14:50:49-06:00" level=debug msg="completed keyexchange" Feb 10 14:50:49 volumio go-librespot[10085]: time="2026-02-10T14:50:49-06:00" level=debug msg="completed challenge" Feb 10 14:50:49 volumio go-librespot[10085]: time="2026-02-10T14:50:49-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:50:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:50:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:50:50 volumio volumio[9639]: info: Initializing connection to go-librespot Websocket Feb 10 14:50:50 volumio volumio[9639]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 14:50:50 volumio sudo[10093]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 10 14:50:50 volumio sudo[10093]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:50 volumio sudo[10095]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 10 14:50:50 volumio sudo[10095]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:50 volumio sudo[10098]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 10 14:50:50 volumio sudo[10098]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:50:50 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 10 14:50:50 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 10 14:50:50 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 10 14:50:50 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 10 14:50:50 volumio sudo[10093]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:50 volumio sudo[10095]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:50 volumio mpd_monitor.sh[10101]: MPD Monitor Service: Starting MPD Monitor Service Feb 10 14:50:50 volumio sudo[10098]: pam_unix(sudo:session): session closed for user root Feb 10 14:50:50 volumio volumio[9639]: info: Successfully started MPD Monitor Feb 10 14:50:50 volumio volumio[9639]: info: Successfully started MPD Monitor Feb 10 14:50:50 volumio volumio[9639]: info: Successfully started MPD Monitor Feb 10 14:50:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 126. Feb 10 14:50:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:52 volumio go-librespot[10105]: go-librespot daemon starting... Feb 10 14:50:52 volumio go-librespot[10106]: time="2026-02-10T14:50:52-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:50:52 volumio go-librespot[10106]: time="2026-02-10T14:50:52-06:00" level=debug msg="app state loaded" Feb 10 14:50:52 volumio go-librespot[10106]: time="2026-02-10T14:50:52-06:00" level=debug msg="stored credentials not found" Feb 10 14:50:52 volumio go-librespot[10106]: time="2026-02-10T14:50:52-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:50:53 volumio go-librespot[10106]: time="2026-02-10T14:50:53-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 14:50:53 volumio go-librespot[10106]: time="2026-02-10T14:50:53-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 14:50:53 volumio go-librespot[10106]: time="2026-02-10T14:50:53-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 14:50:53 volumio go-librespot[10106]: time="2026-02-10T14:50:53-06:00" level=info msg="zeroconf server listening on port 44731" Feb 10 14:50:53 volumio go-librespot[10106]: time="2026-02-10T14:50:53-06:00" level=debug msg="obtained new client token: AADTqvkHbdbVx9Bzgg7G14NR5v/C7LYyc2nXWKJpsU12eTwnhZBJsuQXfEmoBRlPmaXJKqo3iFQB66HR4ps3k4LgR3bjX6WVHu7wfQI/W4ZnIxXfZ87H09xL6RGkQ25Sr+Vle/CvPynUnk8Bz/xYkSVN1Q/vNCyMUNYk+9qJxBiaRSCmYkiUrjIl7cT+1+f3s6IkhQ9wi76tx3f+U+76jfLcdOtvxnBs7f/Ml9Yu6MmItM41Jk+QD0E=" Feb 10 14:50:53 volumio go-librespot[10106]: time="2026-02-10T14:50:53-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 14:50:53 volumio go-librespot[10106]: time="2026-02-10T14:50:53-06:00" level=debug msg="completed keyexchange" Feb 10 14:50:53 volumio go-librespot[10106]: time="2026-02-10T14:50:53-06:00" level=debug msg="completed challenge" Feb 10 14:50:53 volumio go-librespot[10106]: time="2026-02-10T14:50:53-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:50:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:50:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:50:53 volumio volumio[9639]: info: Initializing connection to go-librespot Websocket Feb 10 14:50:53 volumio volumio[9639]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 14:50:55 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 10 14:50:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 127. Feb 10 14:50:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:50:56 volumio go-librespot[10129]: go-librespot daemon starting... Feb 10 14:50:56 volumio go-librespot[10130]: time="2026-02-10T14:50:56-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:50:56 volumio go-librespot[10130]: time="2026-02-10T14:50:56-06:00" level=debug msg="app state loaded" Feb 10 14:50:56 volumio go-librespot[10130]: time="2026-02-10T14:50:56-06:00" level=debug msg="stored credentials not found" Feb 10 14:50:56 volumio go-librespot[10130]: time="2026-02-10T14:50:56-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:50:56 volumio go-librespot[10130]: time="2026-02-10T14:50:56-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 14:50:56 volumio go-librespot[10130]: time="2026-02-10T14:50:56-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 10 14:50:56 volumio go-librespot[10130]: time="2026-02-10T14:50:56-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 10 14:50:56 volumio go-librespot[10130]: time="2026-02-10T14:50:56-06:00" level=info msg="zeroconf server listening on port 44299" Feb 10 14:50:56 volumio volumio[9639]: info: Initializing connection to go-librespot Websocket Feb 10 14:50:57 volumio go-librespot[10130]: time="2026-02-10T14:50:57-06:00" level=debug msg="new websocket client" Feb 10 14:50:57 volumio volumio[9639]: info: Connection to go-librespot Websocket established Feb 10 14:50:57 volumio go-librespot[10130]: time="2026-02-10T14:50:57-06:00" level=debug msg="obtained new client token: AADvP00Jtntb9Lpo/L8E8xfiuHtW9lsvHp0qyxCpMMf2HX4GJROLoCjj5XrBKvpH0GLiVryMKNRkcDBo5I7wAVDPyiCUWCc5zl1i2fJImDm6vXsIVNTrqNTeuIXL8RnN4fHC7JcD8UU0RbaTIQammmUo/7WJ490Xhv9zqJVrF7mGcpG6gG3lns8fkW20kjlR8ic2BQxIKo04pGpG2OcriJuDMA4LE1bd0gGbh4TzaoN86UtQBGIbmxU=" Feb 10 14:50:57 volumio go-librespot[10130]: time="2026-02-10T14:50:57-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 14:50:57 volumio go-librespot[10130]: time="2026-02-10T14:50:57-06:00" level=debug msg="completed keyexchange" Feb 10 14:50:57 volumio go-librespot[10130]: time="2026-02-10T14:50:57-06:00" level=debug msg="completed challenge" Feb 10 14:50:57 volumio go-librespot[10130]: time="2026-02-10T14:50:57-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:50:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:50:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:50:57 volumio volumio[9639]: info: Connection to go-librespot Websocket closed Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 10 14:50:57 volumio volumio[9639]: info: Adding plugin bluetooth to MyMusic Plugins Feb 10 14:50:57 volumio volumio[9639]: info: Adding plugin multiroom to MyMusic Plugins Feb 10 14:50:57 volumio volumio[9639]: info: Adding plugin metavolumio to MyMusic Plugins Feb 10 14:50:57 volumio volumio[9639]: info: Adding plugin cd_controller to MyMusic Plugins Feb 10 14:50:57 volumio volumio[9639]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 10 14:50:57 volumio volumio[9639]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 10 14:50:57 volumio volumio[9639]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 10 14:50:57 volumio volumio[9639]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 10 14:50:59 volumio volumio[9639]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 10 14:50:59 volumio volumio[9639]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 10 14:50:59 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 14:50:59 volumio volumio[9639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 14:50:59 volumio volumio[9639]: info: Starting MyVolumio Remote Streaming Endpoints Feb 10 14:50:59 volumio volumio[9639]: info: MyVolumio login type: Token Feb 10 14:50:59 volumio volumio[9639]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 10 14:50:59 volumio volumio[9639]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 10 14:51:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 128. Feb 10 14:51:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:51:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:51:00 volumio go-librespot[10137]: go-librespot daemon starting... Feb 10 14:51:00 volumio go-librespot[10138]: time="2026-02-10T14:51:00-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:51:00 volumio go-librespot[10138]: time="2026-02-10T14:51:00-06:00" level=debug msg="app state loaded" Feb 10 14:51:00 volumio go-librespot[10138]: time="2026-02-10T14:51:00-06:00" level=debug msg="stored credentials not found" Feb 10 14:51:00 volumio go-librespot[10138]: time="2026-02-10T14:51:00-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:51:00 volumio volumio[9639]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 10 14:51:00 volumio volumio[9639]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 10 14:51:00 volumio volumio[9639]: info: Streaming services startup Feb 10 14:51:00 volumio volumio[9639]: info: Starting Streaming Daemon Feb 10 14:51:00 volumio volumio[9639]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 10 14:51:00 volumio sudo[10146]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 10 14:51:00 volumio sudo[10146]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:00 volumio sudo[10146]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:00 volumio go-librespot[10138]: time="2026-02-10T14:51:00-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 14:51:00 volumio go-librespot[10138]: time="2026-02-10T14:51:00-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 14:51:00 volumio go-librespot[10138]: time="2026-02-10T14:51:00-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 14:51:00 volumio go-librespot[10138]: time="2026-02-10T14:51:00-06:00" level=info msg="zeroconf server listening on port 41329" Feb 10 14:51:00 volumio volumio[9639]: info: Getting Spotify volume Feb 10 14:51:00 volumio volumio[9639]: info: Initializing connection to go-librespot Websocket Feb 10 14:51:00 volumio volumio[9639]: error: Cannot start Volumio Streaming Daemon Feb 10 14:51:00 volumio volumio[9639]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 10 14:51:00 volumio volumio[9639]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 10 14:51:00 volumio volumio[9639]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Feb 10 14:51:00 volumio go-librespot[10138]: time="2026-02-10T14:51:00-06:00" level=debug msg="new websocket client" Feb 10 14:51:00 volumio go-librespot[10138]: time="2026-02-10T14:51:00-06:00" level=debug msg="obtained new client token: AAC1+IjG6gz0/0VLufwdMUY7CMFKNOA7Kfkrkc0l5gKzEmtD7hOLOL1rZiSmOXXMsPSqCl4EAVesXKuZYl0WLfvvp1rdZvVE+NtHQPFdfok/MMJ3C04kIwnPEDfaJ6nwXbFos8aygbbmGKsZeoofuy5GDTL85KHbIUirqyHrFPFpGR9e5bg109SQnP8ZlnZzNczhucYC9+TwOoZuu3A0iwIlBoZ6KcbUpdQdTVRHm83TGVmv2RHguQU1wA==" Feb 10 14:51:00 volumio volumio[9639]: info: Connection to go-librespot Websocket established Feb 10 14:51:00 volumio go-librespot[10138]: time="2026-02-10T14:51:00-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 14:51:00 volumio volumio[9639]: info: CoreCommandRouter::volumioGetState Feb 10 14:51:00 volumio volumio[9639]: info: CorePlayQueue::getTrack 0 Feb 10 14:51:00 volumio go-librespot[10138]: time="2026-02-10T14:51:00-06:00" level=debug msg="completed keyexchange" Feb 10 14:51:00 volumio go-librespot[10138]: time="2026-02-10T14:51:00-06:00" level=debug msg="completed challenge" Feb 10 14:51:00 volumio volumio[9639]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 10 14:51:00 volumio volumio[9639]: SPOTIFY: SPOTIFY VOLUME undefined Feb 10 14:51:00 volumio volumio[9639]: SPOTIFY: VOLUMIO VOLUME 100 Feb 10 14:51:00 volumio volumio[9639]: info: Aligning Spotify Volume to Volumio Volume Feb 10 14:51:00 volumio volumio[9639]: info: CoreCommandRouter::volumioGetState Feb 10 14:51:00 volumio volumio[9639]: info: CorePlayQueue::getTrack 0 Feb 10 14:51:00 volumio volumio[9639]: info: Setting Spotify Volume from Volumio: 100 Feb 10 14:51:01 volumio go-librespot[10138]: time="2026-02-10T14:51:01-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:51:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:51:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:51:01 volumio volumio[9639]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 14:51:01 volumio volumio[9639]: Error: socket hang up Feb 10 14:51:01 volumio volumio[9639]: at connResetException (node:internal/errors:720:14) Feb 10 14:51:01 volumio volumio[9639]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 10 14:51:01 volumio volumio[9639]: at Socket.emit (node:events:526:35) Feb 10 14:51:01 volumio volumio[9639]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 10 14:51:01 volumio volumio[9639]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 10 14:51:01 volumio volumio[9639]: code: 'ECONNRESET', Feb 10 14:51:01 volumio volumio[9639]: response: undefined Feb 10 14:51:01 volumio volumio[9639]: } Feb 10 14:51:01 volumio volumio[9639]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 14:51:01 volumio sudo[10166]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-10 14:50' Feb 10 14:51:01 volumio sudo[10166]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:01 volumio sudo[10166]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:02 volumio volumio-remote-updater[751]: [2026-02-10 14:51:02] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 10 14:51:02 volumio volumio-remote-updater[751]: [2026-02-10 14:51:02] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 10 14:51:02 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:51:02 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 10 14:51:02 volumio systemd[1]: volumio.service: Consumed 52.778s CPU time. Feb 10 14:51:02 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 14:51:03 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 14:51:03 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 4140. Feb 10 14:51:03 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 14:51:03 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 10 14:51:03 volumio systemd[1]: volumio.service: Consumed 52.778s CPU time. Feb 10 14:51:03 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 10 14:51:03 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 14:51:03 volumio kernel: hwmon hwmon1: Voltage normalised Feb 10 14:51:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 129. Feb 10 14:51:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:51:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:51:04 volumio go-librespot[10197]: go-librespot daemon starting... Feb 10 14:51:04 volumio go-librespot[10198]: time="2026-02-10T14:51:04-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:51:04 volumio go-librespot[10198]: time="2026-02-10T14:51:04-06:00" level=debug msg="app state loaded" Feb 10 14:51:04 volumio go-librespot[10198]: time="2026-02-10T14:51:04-06:00" level=debug msg="stored credentials not found" Feb 10 14:51:04 volumio go-librespot[10198]: time="2026-02-10T14:51:04-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:51:04 volumio go-librespot[10198]: time="2026-02-10T14:51:04-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 14:51:04 volumio go-librespot[10198]: time="2026-02-10T14:51:04-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 14:51:04 volumio go-librespot[10198]: time="2026-02-10T14:51:04-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 14:51:04 volumio go-librespot[10198]: time="2026-02-10T14:51:04-06:00" level=info msg="zeroconf server listening on port 34769" Feb 10 14:51:04 volumio go-librespot[10198]: time="2026-02-10T14:51:04-06:00" level=debug msg="obtained new client token: AAD2G9fb4i7sr2Xh4VZtZ8wfBpI1ULu4FtqKjYvgZ1WznmOM7LdTKYL3D+D4rzE4urLBp2zP4GozS10xe7itYxAKDFkdkLJuYl33A+nLrrdbvKy7ygfQQON+MiqvzMwGR4hZWDiRfVbfi5fbVbcNe9iCajFlGE0h9/Xnf/1Zg06SIi3Mn03fhYkFl/NNE8GKww0jzy6QW2g4e+AaJ86VmXCj6e9arufzg5+2bkEZ4kC1pjvfFs78tSTnEg==" Feb 10 14:51:04 volumio go-librespot[10198]: time="2026-02-10T14:51:04-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 14:51:04 volumio go-librespot[10198]: time="2026-02-10T14:51:04-06:00" level=debug msg="completed keyexchange" Feb 10 14:51:04 volumio go-librespot[10198]: time="2026-02-10T14:51:04-06:00" level=debug msg="completed challenge" Feb 10 14:51:04 volumio go-librespot[10198]: time="2026-02-10T14:51:04-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:51:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:51:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:51:05 volumio volumio[10181]: info: ------------------------------------------- Feb 10 14:51:05 volumio volumio[10181]: info: ----- Volumio3 ---- Feb 10 14:51:05 volumio volumio[10181]: info: ------------------------------------------- Feb 10 14:51:05 volumio volumio[10181]: info: ----- System startup ---- Feb 10 14:51:05 volumio volumio[10181]: info: ------------------------------------------- Feb 10 14:51:06 volumio volumio[10181]: info: MYVOLUMIO Environment detected Feb 10 14:51:06 volumio volumio[10181]: info: Plugin folders cleanup Feb 10 14:51:06 volumio volumio[10181]: info: Scanning into folder /volumio/app/plugins/ Feb 10 14:51:06 volumio volumio[10181]: info: Scanning category audio_interface Feb 10 14:51:06 volumio volumio[10181]: info: Scanning category miscellanea Feb 10 14:51:06 volumio volumio[10181]: info: Scanning category music_service Feb 10 14:51:06 volumio volumio[10181]: info: Scanning category plugins.json Feb 10 14:51:06 volumio volumio[10181]: info: Scanning category system_controller Feb 10 14:51:06 volumio volumio[10181]: info: Scanning category user_interface Feb 10 14:51:06 volumio volumio[10181]: info: Scanning into folder /data/plugins/ Feb 10 14:51:06 volumio volumio[10181]: info: Scanning category audio_interface Feb 10 14:51:06 volumio volumio[10181]: info: Scanning category music_service Feb 10 14:51:06 volumio volumio[10181]: info: Scanning category system_controller Feb 10 14:51:06 volumio volumio[10181]: info: Scanning category system_hardware Feb 10 14:51:06 volumio volumio[10181]: info: Scanning category user_interface Feb 10 14:51:06 volumio volumio[10181]: info: Plugin folders cleanup completed Feb 10 14:51:06 volumio volumio[10181]: info: ------------------------------------------- Feb 10 14:51:06 volumio volumio[10181]: info: ----- Core plugins startup ---- Feb 10 14:51:06 volumio volumio[10181]: info: ------------------------------------------- Feb 10 14:51:06 volumio volumio[10181]: info: Loading plugins from folder /volumio/app/plugins/ Feb 10 14:51:06 volumio volumio[10181]: info: Adding plugin upnp to MyMusic Plugins Feb 10 14:51:06 volumio volumio[10181]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 10 14:51:06 volumio volumio[10181]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 10 14:51:06 volumio volumio[10181]: info: Loading plugins from folder /data/plugins/ Feb 10 14:51:06 volumio volumio[10181]: info: Loading plugin "system"... Feb 10 14:51:06 volumio volumio[10181]: info: Loading plugin "appearance"... Feb 10 14:51:07 volumio volumio[10181]: info: Loading plugin "network"... Feb 10 14:51:07 volumio volumio[10181]: info: Refreshing Cached IP Addresses Feb 10 14:51:07 volumio sudo[10218]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 14:51:07 volumio sudo[10218]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:07 volumio sudo[10220]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 14:51:07 volumio volumio[10181]: info: Loading plugin "services"... Feb 10 14:51:07 volumio sudo[10220]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:07 volumio sudo[10220]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:07 volumio volumio[10181]: info: Loading plugin "alsa_controller"... Feb 10 14:51:07 volumio sudo[10218]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:07 volumio sudo[10227]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 10 14:51:07 volumio sudo[10227]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:07 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 14:51:07 volumio volumio[10181]: info: Loading plugin "wizard"... Feb 10 14:51:07 volumio volumio[10181]: info: Loading plugin "networkfs"... Feb 10 14:51:07 volumio volumio[10181]: info: Starting Udev Watcher for removable devices Feb 10 14:51:07 volumio volumio[10181]: info: Ignoring mount for partition: boot Feb 10 14:51:07 volumio volumio[10181]: info: Ignoring mount for partition: volumio Feb 10 14:51:07 volumio volumio[10181]: info: Ignoring mount for partition: volumio_data Feb 10 14:51:07 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 10 14:51:07 volumio volumio[10181]: info: Mounting Device Wikipedia Feb 10 14:51:07 volumio sudo[10258]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Wikipedia -o noatime Feb 10 14:51:07 volumio sudo[10258]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:07 volumio sudo[10258]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:07 volumio volumio[10181]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Feb 10 14:51:07 volumio volumio[10181]: dmesg(1) may have more information after failed mount system call. Feb 10 14:51:07 volumio volumio[10181]: error: Failed to mount Wikipedia: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sda1" "/mnt/USB/Wikipedia" -o noatime Feb 10 14:51:07 volumio volumio[10181]: mount: /media/Wikipedia: /dev/sda1 already mounted on /media/Wikipedia. Feb 10 14:51:07 volumio volumio[10181]: dmesg(1) may have more information after failed mount system call. Feb 10 14:51:07 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 14:51:07 volumio volumio[10181]: info: Loading plugin "volumio_command_line_client"... Feb 10 14:51:07 volumio volumio[10181]: info: Loading plugin "upnp"... Feb 10 14:51:07 volumio volumio[10181]: info: [1770756667724] Starting Upmpd Daemon Feb 10 14:51:07 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 14:51:07 volumio volumio[10181]: info: Loading plugin "my_music"... Feb 10 14:51:07 volumio volumio[10181]: info: Loading plugin "mpd"... Feb 10 14:51:07 volumio volumio-remote-updater[751]: [2026-02-10 14:51:07] [connect] Successful connection Feb 10 14:51:07 volumio sudo[10227]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 130. Feb 10 14:51:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:51:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:51:08 volumio go-librespot[10260]: go-librespot daemon starting... Feb 10 14:51:08 volumio go-librespot[10261]: time="2026-02-10T14:51:08-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:51:08 volumio go-librespot[10261]: time="2026-02-10T14:51:08-06:00" level=debug msg="app state loaded" Feb 10 14:51:08 volumio go-librespot[10261]: time="2026-02-10T14:51:08-06:00" level=debug msg="stored credentials not found" Feb 10 14:51:08 volumio go-librespot[10261]: time="2026-02-10T14:51:08-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:51:08 volumio volumio[10181]: info: Loading plugin "upnp_browser"... Feb 10 14:51:08 volumio go-librespot[10261]: time="2026-02-10T14:51:08-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 14:51:08 volumio go-librespot[10261]: time="2026-02-10T14:51:08-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 14:51:08 volumio go-librespot[10261]: time="2026-02-10T14:51:08-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 14:51:08 volumio go-librespot[10261]: time="2026-02-10T14:51:08-06:00" level=info msg="zeroconf server listening on port 33563" Feb 10 14:51:08 volumio go-librespot[10261]: time="2026-02-10T14:51:08-06:00" level=debug msg="obtained new client token: AACMfVwLgXbopE0Tz/7oHoVqLWkl43HeOsU3BHDdcyTyemUBF/m+sUjUcoFN3vPoyc04FyxA3dE3M7QlbZXXYOsD5a1WG32mS7N4sq6RK8e5I2J+OaPNgBJdQyN0z4oMzMbOhPM++AXxXSaeiLf84W7oeXq4vMAIoFlddVP+rVtMupM19ufFjsyw0ZBd9BI0UpEGbG6oDFroNqGmEjBAjVW9UXO9fV7Kc9+gOEHXr6+VjE6jobo4UUaOTQ==" Feb 10 14:51:08 volumio go-librespot[10261]: time="2026-02-10T14:51:08-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 14:51:08 volumio go-librespot[10261]: time="2026-02-10T14:51:08-06:00" level=debug msg="completed keyexchange" Feb 10 14:51:08 volumio go-librespot[10261]: time="2026-02-10T14:51:08-06:00" level=debug msg="completed challenge" Feb 10 14:51:08 volumio go-librespot[10261]: time="2026-02-10T14:51:08-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:51:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:51:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:51:10 volumio volumio[10181]: info: Loading plugin "alarm-clock"... Feb 10 14:51:11 volumio volumio[10181]: info: Loading plugin "airplay_emulation"... Feb 10 14:51:11 volumio volumio[10181]: info: Starting Shairport Sync Feb 10 14:51:11 volumio volumio[10181]: info: Loading plugin "last_100"... Feb 10 14:51:11 volumio volumio[10181]: info: Loading plugin "webradio"... Feb 10 14:51:11 volumio volumio[10181]: info: Loading plugin "i2s_dacs"... Feb 10 14:51:11 volumio volumio[10181]: info: I2S DAC not set, start Auto-detection Feb 10 14:51:11 volumio volumio[10181]: info: Loading plugin "volumiodiscovery"... Feb 10 14:51:11 volumio volumio[10181]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 14:51:11 volumio volumio[10181]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 14:51:11 volumio volumio[10181]: *** WARNING *** For more information see Feb 10 14:51:11 volumio volumio[10181]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 14:51:11 volumio volumio[10181]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 14:51:11 volumio volumio[10181]: *** WARNING *** For more information see Feb 10 14:51:11 volumio node[10181]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 14:51:11 volumio node[10181]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 14:51:11 volumio node[10181]: *** WARNING *** For more information see Feb 10 14:51:11 volumio node[10181]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 14:51:11 volumio node[10181]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 14:51:11 volumio node[10181]: *** WARNING *** For more information see Feb 10 14:51:11 volumio volumio[10181]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 10 14:51:11 volumio volumio[10181]: info: Discovery: Started advertising with name: Volumio Feb 10 14:51:11 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 14:51:11 volumio volumio[10181]: info: Loading plugin "bandcamp"... Feb 10 14:51:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 131. Feb 10 14:51:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:51:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:51:12 volumio go-librespot[10273]: go-librespot daemon starting... Feb 10 14:51:12 volumio go-librespot[10274]: time="2026-02-10T14:51:12-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:51:12 volumio go-librespot[10274]: time="2026-02-10T14:51:12-06:00" level=debug msg="app state loaded" Feb 10 14:51:12 volumio go-librespot[10274]: time="2026-02-10T14:51:12-06:00" level=debug msg="stored credentials not found" Feb 10 14:51:12 volumio go-librespot[10274]: time="2026-02-10T14:51:12-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:51:12 volumio go-librespot[10274]: time="2026-02-10T14:51:12-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 14:51:12 volumio go-librespot[10274]: time="2026-02-10T14:51:12-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 14:51:12 volumio go-librespot[10274]: time="2026-02-10T14:51:12-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 14:51:12 volumio go-librespot[10274]: time="2026-02-10T14:51:12-06:00" level=info msg="zeroconf server listening on port 35451" Feb 10 14:51:12 volumio go-librespot[10274]: time="2026-02-10T14:51:12-06:00" level=debug msg="obtained new client token: AABAe70AqcFv5tKeMVjfUkta6q0m2GQi1fSr6bPCwMpZwod8JX1Ff/iqLpvxoX+sfXwI/bB/ZvbgAlow4rA+BFUm1eTk9WS5mIxJ/SZ1X6eq3WubwJr+ZuCo70WN/QsYCjj74KKioXDlDSqffzZV6/HOSiOYQz0FUZ/ccOt9jTjMZ05/9D4MC/5UkmKRf/cD2Ddo90BinD0mWvY4lNQ0vE4XZ7vhcI/N6R3Hdqmn8tGBFyDx5uaIQSiO0A==" Feb 10 14:51:12 volumio go-librespot[10274]: time="2026-02-10T14:51:12-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Feb 10 14:51:12 volumio volumio[10181]: info: Plugin calmradio is not enabled Feb 10 14:51:12 volumio volumio[10181]: info: Loading plugin "soundcloud"... Feb 10 14:51:12 volumio go-librespot[10274]: time="2026-02-10T14:51:12-06:00" level=debug msg="connected to ap-guc3.spotify.com:443" Feb 10 14:51:12 volumio go-librespot[10274]: time="2026-02-10T14:51:12-06:00" level=debug msg="completed keyexchange" Feb 10 14:51:12 volumio go-librespot[10274]: time="2026-02-10T14:51:12-06:00" level=debug msg="completed challenge" Feb 10 14:51:12 volumio go-librespot[10274]: time="2026-02-10T14:51:12-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:51:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:51:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:51:13 volumio volumio[10181]: info: Loading plugin "spop"... Feb 10 14:51:13 volumio kernel: hwmon hwmon1: Voltage normalised Feb 10 14:51:14 volumio volumio[10181]: info: Loading plugin "squeezelite_mc"... Feb 10 14:51:14 volumio volumio[10181]: info: Loading plugin "youtube2"... Feb 10 14:51:15 volumio volumio[10181]: info: Loading plugin "ytcr"... Feb 10 14:51:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 132. Feb 10 14:51:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:51:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:51:16 volumio go-librespot[10283]: go-librespot daemon starting... Feb 10 14:51:16 volumio go-librespot[10284]: time="2026-02-10T14:51:16-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:51:16 volumio go-librespot[10284]: time="2026-02-10T14:51:16-06:00" level=debug msg="app state loaded" Feb 10 14:51:16 volumio go-librespot[10284]: time="2026-02-10T14:51:16-06:00" level=debug msg="stored credentials not found" Feb 10 14:51:16 volumio go-librespot[10284]: time="2026-02-10T14:51:16-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:51:16 volumio go-librespot[10284]: time="2026-02-10T14:51:16-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 14:51:16 volumio go-librespot[10284]: time="2026-02-10T14:51:16-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 14:51:16 volumio go-librespot[10284]: time="2026-02-10T14:51:16-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 14:51:16 volumio go-librespot[10284]: time="2026-02-10T14:51:16-06:00" level=info msg="zeroconf server listening on port 46199" Feb 10 14:51:16 volumio go-librespot[10284]: time="2026-02-10T14:51:16-06:00" level=debug msg="obtained new client token: AAC+Mb8hLGZY0nyJ3Bq1CqRMndTzR6wPIWOcPulbpW26fr0im8RCtfoyw7qv+VKmstPGyC+xgQr69g0596cHcHc9W6X+OvNbVTuXMmhvbjj2N9FvEGZj6mj6PkiuAo21i5/5JNcFunNlI7G7KzeAH7ZmL3afR8yinnlSGQzTGchywMSl04GWgOZ4TsIu/c1tLItCZ+PGE3NVKgKR3MXziBVA5L94j3YC6lytpxvnAe5EIaSdYyW+Be/ZcQ==" Feb 10 14:51:16 volumio go-librespot[10284]: time="2026-02-10T14:51:16-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 14:51:16 volumio go-librespot[10284]: time="2026-02-10T14:51:16-06:00" level=debug msg="completed keyexchange" Feb 10 14:51:16 volumio go-librespot[10284]: time="2026-02-10T14:51:16-06:00" level=debug msg="completed challenge" Feb 10 14:51:16 volumio go-librespot[10284]: time="2026-02-10T14:51:16-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:51:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:51:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:51:16 volumio volumio[10181]: info: Loading plugin "ytmusic"... Feb 10 14:51:17 volumio volumio[10181]: info: Plugin now_playing is not enabled Feb 10 14:51:17 volumio volumio[10181]: info: Loading plugin "outputs"... Feb 10 14:51:17 volumio volumio[10181]: info: Loading plugin "albumart"... Feb 10 14:51:17 volumio volumio[10181]: info: Plugin example_plugin is not enabled Feb 10 14:51:17 volumio volumio[10181]: info: Loading plugin "inputs"... Feb 10 14:51:17 volumio volumio[10181]: info: Loading plugin "updater_comm"... Feb 10 14:51:17 volumio volumio[10181]: info: Plugin mpdemulation is not enabled Feb 10 14:51:17 volumio volumio[10181]: info: Loading plugin "rest_api"... Feb 10 14:51:17 volumio volumio[10181]: info: Loading plugin "websocket"... Feb 10 14:51:17 volumio volumio[10181]: info: Starting Socket.io Server version 1.7.4 Feb 10 14:51:17 volumio volumio[10181]: info: Plugin fusiondsp is not enabled Feb 10 14:51:17 volumio volumio[10181]: info: Plugin mpdoutput is not enabled Feb 10 14:51:17 volumio volumio[10181]: info: Plugin RoonBridge is not enabled Feb 10 14:51:17 volumio volumio[10181]: info: Loading plugin "podcast"... Feb 10 14:51:17 volumio volumio[10181]: info: ControllerPodcast::constructor Feb 10 14:51:17 volumio volumio[10181]: info: Loading plugin "volusonic"... Feb 10 14:51:17 volumio volumio[10291]: Forking 3 albumart workers Feb 10 14:51:19 volumio volumio[10181]: info: Applying required configuration parameters for plugin volusonic Feb 10 14:51:19 volumio volumio[10181]: info: Loading plugin "backup_restore"... Feb 10 14:51:19 volumio volumio[10315]: Starting albumart workers Feb 10 14:51:19 volumio volumio[10317]: Starting albumart workers Feb 10 14:51:19 volumio volumio[10316]: Starting albumart workers Feb 10 14:51:19 volumio volumio[10181]: info: Applying required configuration parameters for plugin backup_restore Feb 10 14:51:19 volumio volumio[10181]: info: Plugin rpi_eeprom_config is not enabled Feb 10 14:51:19 volumio volumio[10181]: info: Plugin rpi_eeprom_updater is not enabled Feb 10 14:51:19 volumio volumio[10181]: info: Loading plugin "scheduledrestart"... Feb 10 14:51:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 133. Feb 10 14:51:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:51:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:51:19 volumio go-librespot[10345]: go-librespot daemon starting... Feb 10 14:51:19 volumio volumio[10181]: info: Applying required configuration parameters for plugin scheduledrestart Feb 10 14:51:19 volumio go-librespot[10346]: time="2026-02-10T14:51:19-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:51:19 volumio go-librespot[10346]: time="2026-02-10T14:51:19-06:00" level=debug msg="app state loaded" Feb 10 14:51:19 volumio go-librespot[10346]: time="2026-02-10T14:51:19-06:00" level=debug msg="stored credentials not found" Feb 10 14:51:19 volumio volumio[10181]: info: Plugin Bluetoothremote is not enabled Feb 10 14:51:19 volumio volumio[10181]: info: Plugin music_services_shield is not enabled Feb 10 14:51:19 volumio go-librespot[10346]: time="2026-02-10T14:51:19-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:51:19 volumio volumio[10181]: info: Loading plugin "Systeminfo"... Feb 10 14:51:20 volumio go-librespot[10346]: time="2026-02-10T14:51:20-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 14:51:20 volumio go-librespot[10346]: time="2026-02-10T14:51:20-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 14:51:20 volumio go-librespot[10346]: time="2026-02-10T14:51:20-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 14:51:20 volumio go-librespot[10346]: time="2026-02-10T14:51:20-06:00" level=info msg="zeroconf server listening on port 41071" Feb 10 14:51:20 volumio volumio-remote-updater[751]: [2026-02-10 14:51:20] [connect] Successful connection Feb 10 14:51:20 volumio go-librespot[10346]: time="2026-02-10T14:51:20-06:00" level=debug msg="obtained new client token: AAB1xoQ02nZLSmmnjXBK7HiwKLvS+JUicywjzxd/sAH0oUwVCERpV9hivbPtsyPFGOgoMdUq57cMt40dJ4I47ZoC4zGrFXlutAsbA6Czk8ix6CTFaGlMDwGNrq7qSM5sBkKbLSlTU9xdKVO4k5ZIMq3mJaoB9yvUVWZYf5CuIzQar6b0uu41gijhYf7Q2vyatEBQhkT3Zxj1bOeVwrkfmc6yprh1ZYRSnb1uJ2E6RITe/o1GMN/gg/c/Vg==" Feb 10 14:51:20 volumio volumio[10181]: info: Plugin peppymeterbasic is not enabled Feb 10 14:51:20 volumio volumio[10181]: info: Loading plugin "peppyspectrum"... Feb 10 14:51:20 volumio go-librespot[10346]: time="2026-02-10T14:51:20-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Feb 10 14:51:20 volumio go-librespot[10346]: time="2026-02-10T14:51:20-06:00" level=debug msg="connected to ap-guc3.spotify.com:443" Feb 10 14:51:20 volumio go-librespot[10346]: time="2026-02-10T14:51:20-06:00" level=debug msg="completed keyexchange" Feb 10 14:51:20 volumio go-librespot[10346]: time="2026-02-10T14:51:20-06:00" level=debug msg="completed challenge" Feb 10 14:51:20 volumio go-librespot[10346]: time="2026-02-10T14:51:20-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:51:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:51:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:51:20 volumio volumio[10181]: info: Loading i18n strings for locale en Feb 10 14:51:20 volumio volumio[10181]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 10 14:51:20 volumio volumio[10181]: Updating browse sources language Feb 10 14:51:20 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::initPlayerControls Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 14:51:21 volumio volumio[10181]: Express server listening on port 3000 Feb 10 14:51:21 volumio volumio[10181]: [Metrics] WebUI: 16s 276.57ms Feb 10 14:51:21 volumio volumio[10181]: info: CoreStateMachine::resetVolumioState Feb 10 14:51:21 volumio volumio[10181]: info: CoreStateMachine::getcurrentVolume Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 14:51:21 volumio sudo[10376]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 14:51:21 volumio sudo[10376]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:21 volumio sudo[10376]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:21 volumio sudo[10378]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 14:51:21 volumio sudo[10378]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:21 volumio sudo[10378]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:21 volumio volumio[10181]: info: Volumio Network Manager: Network status updated: 1 Feb 10 14:51:21 volumio volumio[10181]: info: VolumeController:: Volume=100 Mute =false Feb 10 14:51:21 volumio volumio[10181]: info: CoreStateMachine::pushState Feb 10 14:51:21 volumio volumio[10181]: info: CorePlayQueue::getTrack 0 Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::volumioPushState Feb 10 14:51:21 volumio volumio[10181]: info: CoreStateMachine::updateTrackBlock Feb 10 14:51:21 volumio volumio[10181]: info: CorePlayQueue::getTrackBlock Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 14:51:21 volumio volumio-remote-updater[751]: [2026-02-10 14:51:21] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770756680 101 Feb 10 14:51:21 volumio volumio[10181]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 10 14:51:21 volumio volumio[10181]: info: Reloading queue from file Feb 10 14:51:21 volumio volumio[10181]: info: CoreStateMachine::setRepeat null single undefined Feb 10 14:51:21 volumio volumio[10181]: info: CoreStateMachine::pushState Feb 10 14:51:21 volumio volumio[10181]: info: CorePlayQueue::getTrack 0 Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::volumioPushState Feb 10 14:51:21 volumio volumio[10181]: info: CoreStateMachine::setRandom null Feb 10 14:51:21 volumio volumio[10181]: info: CoreStateMachine::pushState Feb 10 14:51:21 volumio volumio[10181]: info: CorePlayQueue::getTrack 0 Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::volumioPushState Feb 10 14:51:21 volumio volumio[10181]: info: Setting Device type: Raspberry PI Feb 10 14:51:21 volumio volumio[10181]: info: VolumeController:: Volume=100 Mute =false Feb 10 14:51:21 volumio volumio[10181]: info: CoreStateMachine::pushState Feb 10 14:51:21 volumio volumio[10181]: info: CorePlayQueue::getTrack 0 Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::volumioPushState Feb 10 14:51:21 volumio volumio[10181]: info: Completed loading Core Plugins Feb 10 14:51:21 volumio volumio[10181]: info: Preparing to generate the ALSA configuration file Feb 10 14:51:21 volumio sudo[10392]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 10 14:51:21 volumio sudo[10392]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:21 volumio volumio[10181]: info: Discovery: adding a135e40e-a404-457b-98f5-36bf71c75954 Feb 10 14:51:21 volumio volumio[10181]: info: Discovery: Found device Volumio Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::volumioGetState Feb 10 14:51:21 volumio volumio[10181]: info: CorePlayQueue::getTrack 0 Feb 10 14:51:21 volumio volumio[10181]: info: Discovery: this is already registered, a135e40e-a404-457b-98f5-36bf71c75954 Feb 10 14:51:21 volumio volumio[10181]: info: Discovery: Found device Volumio Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::volumioGetState Feb 10 14:51:21 volumio volumio[10181]: info: CorePlayQueue::getTrack 0 Feb 10 14:51:21 volumio sudo[10392]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:21 volumio volumio[10181]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 10 14:51:21 volumio volumio[10181]: info: Reading ALSA contributions from plugins. Feb 10 14:51:21 volumio volumio[10181]: info: Upmpdcli Daemon Started Feb 10 14:51:21 volumio volumio[10181]: info: Asound.conf file unchanged, so no further update is needed Feb 10 14:51:21 volumio volumio[10181]: info: Output device has changed, restarting MPD Feb 10 14:51:21 volumio volumio[10181]: info: Output device has changed, restarting Shairport Sync Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 14:51:21 volumio sudo[10395]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 14:51:21 volumio sudo[10395]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:21 volumio sudo[10395]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:21 volumio sudo[10397]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 14:51:21 volumio sudo[10397]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:21 volumio volumio[10181]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 14:51:21 volumio volumio[10181]: info: ___________ START PLUGINS ___________ Feb 10 14:51:21 volumio volumio[10181]: info: ControllerMpd::onStart: Initializing MPD Feb 10 14:51:21 volumio volumio[10181]: info: Creating MPD Configuration file Feb 10 14:51:21 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 14:51:21 volumio sudo[10405]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 14:51:21 volumio volumio[10181]: info: [1770756681682] CoreMusicLibrary::Adding element Media Servers Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:51:21 volumio sudo[10405]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:21 volumio sudo[10405]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:21 volumio sudo[10407]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 14:51:21 volumio sudo[10407]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 14:51:21 volumio volumio[10181]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 14:51:21 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 14:51:21 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 14:51:21 volumio systemd[1]: mpd.service: Consumed 4.117s CPU time. Feb 10 14:51:21 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 14:51:21 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 14:51:21 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 14:51:21 volumio volumio[10181]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 14:51:21 volumio volumio[10181]: info: [1770756681807] CoreMusicLibrary::Adding element Last_100 Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 14:51:21 volumio volumio[10181]: info: [1770756681811] CoreMusicLibrary::Adding element Webradio Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 14:51:21 volumio volumio[10181]: info: Initializing BBC Radios Feb 10 14:51:21 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 14:51:21 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 14:51:21 volumio volumio[10181]: info: [1770756681895] CoreMusicLibrary::Adding element Bandcamp Discover Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:51:21 volumio volumio[10181]: Cannot find translation for source Bandcamp Discover Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 14:51:21 volumio volumio[10181]: info: [1770756681909] CoreMusicLibrary::Adding element SoundCloud Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:51:21 volumio volumio[10181]: Cannot find translation for source Bandcamp Discover Feb 10 14:51:21 volumio volumio[10181]: Cannot find translation for source SoundCloud Feb 10 14:51:21 volumio volumio[10181]: info: Creating Spotify config file Feb 10 14:51:21 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:22 volumio sudo[10427]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 10 14:51:22 volumio sudo[10427]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 10 14:51:22 volumio sudo[10427]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:22 volumio volumio[10181]: info: [squeezelite_mc] Starting proxy server... Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 14:51:22 volumio volumio[10181]: info: [1770756682262] CoreMusicLibrary::Adding element YouTube2 Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:51:22 volumio volumio[10181]: Cannot find translation for source Bandcamp Discover Feb 10 14:51:22 volumio volumio[10181]: Cannot find translation for source SoundCloud Feb 10 14:51:22 volumio volumio[10181]: Cannot find translation for source YouTube2 Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 14:51:22 volumio volumio[10181]: info: [1770756682281] CoreMusicLibrary::Adding element YouTube Music Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:51:22 volumio volumio[10181]: Cannot find translation for source Bandcamp Discover Feb 10 14:51:22 volumio volumio[10181]: Cannot find translation for source SoundCloud Feb 10 14:51:22 volumio volumio[10181]: Cannot find translation for source YouTube2 Feb 10 14:51:22 volumio volumio[10181]: Cannot find translation for source YouTube Music Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 14:51:22 volumio volumio[10181]: info: [1770756682292] CoreMusicLibrary::Adding element Podcast Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:51:22 volumio volumio[10181]: Cannot find translation for source Bandcamp Discover Feb 10 14:51:22 volumio volumio[10181]: Cannot find translation for source SoundCloud Feb 10 14:51:22 volumio volumio[10181]: Cannot find translation for source YouTube2 Feb 10 14:51:22 volumio volumio[10181]: Cannot find translation for source YouTube Music Feb 10 14:51:22 volumio volumio[10181]: Cannot find translation for source Podcast Feb 10 14:51:22 volumio volumio[10181]: info: Loading i18n strings for locale en Feb 10 14:51:22 volumio volumio[10181]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Feb 10 14:51:22 volumio volumio[10181]: Updating browse sources language Feb 10 14:51:22 volumio volumio[10181]: Cannot find translation for source Bandcamp Discover Feb 10 14:51:22 volumio volumio[10181]: Cannot find translation for source SoundCloud Feb 10 14:51:22 volumio volumio[10181]: Cannot find translation for source YouTube2 Feb 10 14:51:22 volumio volumio[10181]: Cannot find translation for source YouTube Music Feb 10 14:51:22 volumio volumio[10181]: Cannot find translation for source Podcast Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:51:22 volumio volumio[10181]: Cannot find translation for source Bandcamp Discover Feb 10 14:51:22 volumio volumio[10181]: Cannot find translation for source SoundCloud Feb 10 14:51:22 volumio volumio[10181]: Cannot find translation for source YouTube2 Feb 10 14:51:22 volumio volumio[10181]: Cannot find translation for source YouTube Music Feb 10 14:51:22 volumio volumio[10181]: Cannot find translation for source Podcast Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 14:51:22 volumio volumio[10181]: info: [1770756682339] CoreMusicLibrary::Adding element Volusonic Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:51:22 volumio volumio[10181]: Cannot find translation for source Bandcamp Discover Feb 10 14:51:22 volumio volumio[10181]: Cannot find translation for source SoundCloud Feb 10 14:51:22 volumio volumio[10181]: Cannot find translation for source YouTube2 Feb 10 14:51:22 volumio volumio[10181]: Cannot find translation for source YouTube Music Feb 10 14:51:22 volumio volumio[10181]: Cannot find translation for source Podcast Feb 10 14:51:22 volumio volumio[10181]: Cannot find translation for source Volusonic Feb 10 14:51:22 volumio volumio[10181]: info: Scheduling reboots with hours: 0, minutes: 0 in timezone: America/Chicago Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Feb 10 14:51:22 volumio volumio[10181]: info: Volumio Calling Home Feb 10 14:51:22 volumio volumio[10181]: info: [squeezelite_mc] Proxy server started on port 43185 Feb 10 14:51:22 volumio volumio[10181]: info: Preparing to generate the ALSA configuration file Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 14:51:22 volumio volumio[10181]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Feb 10 14:51:22 volumio volumio[10181]: info: Reading ALSA contributions from plugins. Feb 10 14:51:22 volumio volumio[10181]: info: MPD Permissions set Feb 10 14:51:22 volumio volumio[10181]: info: MPD Permissions set Feb 10 14:51:22 volumio volumio[10181]: info: Spotify config file written Feb 10 14:51:22 volumio sudo[10442]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 10 14:51:22 volumio sudo[10442]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:22 volumio volumio[10181]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 10 14:51:22 volumio volumio[10181]: info: VolumeController:: Volume=100 Mute =false Feb 10 14:51:22 volumio volumio[10181]: info: CoreStateMachine::pushState Feb 10 14:51:22 volumio volumio[10181]: info: CorePlayQueue::getTrack 0 Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::volumioPushState Feb 10 14:51:22 volumio volumio[10181]: info: [squeezelite_mc] Server discovery started Feb 10 14:51:22 volumio volumio[10181]: info: [squeezelite_mc] Player finder started Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 14:51:22 volumio volumio[10181]: info: [squeezelite_mc] Executing aplay -D hw:1 --nonblock -f MPEG /dev/zero 2>&1 || true Feb 10 14:51:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 14:51:22 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:22 volumio volumio[10181]: info: No need to fix Spotify hosts Feb 10 14:51:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:51:22 volumio go-librespot[10446]: go-librespot daemon starting... Feb 10 14:51:22 volumio sudo[10442]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:22 volumio go-librespot[10457]: time="2026-02-10T14:51:22-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:51:22 volumio go-librespot[10457]: time="2026-02-10T14:51:22-06:00" level=debug msg="app state loaded" Feb 10 14:51:22 volumio go-librespot[10457]: time="2026-02-10T14:51:22-06:00" level=debug msg="stored credentials not found" Feb 10 14:51:22 volumio go-librespot[10457]: time="2026-02-10T14:51:22-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:51:23 volumio volumio[10181]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 10 14:51:23 volumio volumio[10181]: info: Volumio called home Feb 10 14:51:23 volumio volumio[10181]: info: [squeezelite_mc] Card 1 supports the following ALSA formats: ["U8","S16_LE"] Feb 10 14:51:23 volumio volumio[10181]: info: [squeezelite_mc] Starting Squeezelite service with params: {"type":"basic","playerName":"volumio","dsdFormat":null,"card":"1","mixerType":"Hardware","mixer":"PCM"} Feb 10 14:51:23 volumio volumio[10181]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Feb 10 14:51:23 volumio sudo[10467]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/alsa/100-squeezelite.conf.template.out /etc/alsa/conf.d/100-squeezelite.conf Feb 10 14:51:23 volumio sudo[10467]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:23 volumio volumio[10181]: info: Starting Shairport Sync Feb 10 14:51:23 volumio sudo[10467]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:23 volumio go-librespot[10457]: time="2026-02-10T14:51:23-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 14:51:23 volumio go-librespot[10457]: time="2026-02-10T14:51:23-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 14:51:23 volumio go-librespot[10457]: time="2026-02-10T14:51:23-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 14:51:23 volumio volumio[10181]: info: Starting Shairport Sync Feb 10 14:51:23 volumio volumio[10181]: info: Starting Shairport Sync Feb 10 14:51:23 volumio go-librespot[10457]: time="2026-02-10T14:51:23-06:00" level=info msg="zeroconf server listening on port 33415" Feb 10 14:51:23 volumio sudo[10471]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 14:51:23 volumio sudo[10471]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:23 volumio sudo[10474]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 14:51:23 volumio sudo[10474]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:23 volumio volumio[10181]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 14:51:23 volumio volumio[10181]: SPOTIFY: BQBdtU6fggiELp7TKo1lZRah9QcKebYyqdavea4vjwd-Kk6erOGIdWwvh32TDy_osU5Cno27yVhCiZWRabYOQQ4eJrYpjsCl7UxlGUPYw6UDVMyMZhhPAyJrI12TBrv_s-XuOEbZSozLFWau25XJkYFfPHg3sO8u9H2mA1x8CcPAHzzj-RBtPnm6o6Y3yCs_DdO995_Ln1UwukEnM3grOLFl3Zh2SxIrclcPYnE Feb 10 14:51:23 volumio volumio[10181]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 14:51:23 volumio volumio[10181]: info: New Spotify access token = BQBdtU6fggiELp7TKo1lZRah9QcKebYyqdavea4vjwd-Kk6erOGIdWwvh32TDy_osU5Cno27yVhCiZWRabYOQQ4eJrYpjsCl7UxlGUPYw6UDVMyMZhhPAyJrI12TBrv_s-XuOEbZSozLFWau25XJkYFfPHg3sO8u9H2mA1x8CcPAHzzj-RBtPnm6o6Y3yCs_DdO995_Ln1UwukEnM3grOLFl3Zh2SxIrclcPYnE Feb 10 14:51:23 volumio volumio[10181]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 10 14:51:23 volumio sudo[10476]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 14:51:23 volumio sudo[10476]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:23 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 14:51:23 volumio go-librespot[10457]: time="2026-02-10T14:51:23-06:00" level=debug msg="obtained new client token: AABkYr5jatBrUhi3Lpl3cfLmdeKkaN+o/DZgT0HGnoBsUrhw7QxV15xIuLWuDhIKsWLJVJ+fXaaJnfbdIxeEjTNp6Zs5NE4tqj0o0DpcPCmA3f9Arlh8OKGE1CWquUCkuaZyaDaUrA7MkM/MyEXeEE/uDCQavnLMn/R6vk89ppbBWluarWXrCWuNGZjd3VzbVbrIwnYBgCjPcDEa+IrB9bBKjoEDSv9DV6TPAHzlKN6VAaDcyg45kpVT9Q==" Feb 10 14:51:23 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 14:51:23 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 14:51:23 volumio systemd[1]: shairport-sync.service: Consumed 2.067s CPU time. Feb 10 14:51:23 volumio go-librespot[10457]: time="2026-02-10T14:51:23-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 14:51:23 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 14:51:23 volumio sudo[10471]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:23 volumio sudo[10474]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:23 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 14:51:23 volumio go-librespot[10457]: time="2026-02-10T14:51:23-06:00" level=debug msg="completed keyexchange" Feb 10 14:51:23 volumio go-librespot[10457]: time="2026-02-10T14:51:23-06:00" level=debug msg="completed challenge" Feb 10 14:51:23 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 14:51:23 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 14:51:23 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 14:51:23 volumio volumio[10181]: info: [squeezelite_mc] Executing alsactl -L -R nrestore Feb 10 14:51:23 volumio sudo[10476]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:23 volumio go-librespot[10457]: time="2026-02-10T14:51:23-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:51:23 volumio volumio[10181]: info: Asound.conf file unchanged, so no further update is needed Feb 10 14:51:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:51:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:51:23 volumio volumio[10181]: info: Output device has changed, restarting MPD Feb 10 14:51:23 volumio sudo[10484]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/sbin/alsactl -L -R nrestore Feb 10 14:51:23 volumio sudo[10484]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:23 volumio volumio[10181]: info: Output device has changed, restarting Shairport Sync Feb 10 14:51:23 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:23 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 14:51:23 volumio sudo[10484]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:23 volumio sudo[10486]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 14:51:23 volumio sudo[10486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:23 volumio sudo[10486]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:23 volumio sudo[10501]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 14:51:23 volumio sudo[10501]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:23 volumio volumio[10181]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 14:51:23 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 14:51:23 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 14:51:23 volumio systemd[1]: mpd.service: Consumed 1.695s CPU time. Feb 10 14:51:23 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 14:51:23 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 14:51:23 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 14:51:23 volumio volumio[10181]: info: Shairport-Sync Started Feb 10 14:51:23 volumio volumio[10181]: Error adding Membership: Error: addMembership EINVAL Feb 10 14:51:23 volumio volumio[10181]: info: Shairport-Sync Started Feb 10 14:51:23 volumio volumio[10181]: info: MPD Permissions set Feb 10 14:51:23 volumio volumio[10181]: info: [squeezelite_mc] Executing cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Feb 10 14:51:23 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 14:51:23 volumio volumio[10181]: info: Shairport-Sync Started Feb 10 14:51:23 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 14:51:23 volumio sudo[10516]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/cp /data/plugins/music_service/squeezelite_mc/dist/lib/../templates/systemd/squeezelite.service.template.out /etc/systemd/system/squeezelite.service Feb 10 14:51:23 volumio sudo[10516]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:23 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:23 volumio sudo[10516]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:23 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:23 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:23 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:23 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:23 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:23 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:23 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:23 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 14:51:23 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:23 volumio volumio[10181]: info: CoreCommandRouter::volumioGetState Feb 10 14:51:23 volumio volumio[10181]: info: CorePlayQueue::getTrack 0 Feb 10 14:51:23 volumio volumio[10181]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl daemon-reload || true Feb 10 14:51:24 volumio sudo[10525]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Feb 10 14:51:24 volumio sudo[10525]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:24 volumio volumio[10181]: info: Starting Shairport Sync Feb 10 14:51:24 volumio systemd[1]: Reloading. Feb 10 14:51:24 volumio sudo[10528]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 14:51:24 volumio sudo[10528]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:24 volumio sudo[10517]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 10 14:51:24 volumio sudo[10517]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 10 14:51:24 volumio sudo[10517]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:24 volumio volumio[10181]: SPOTIFY: User informations: {"display_name":"Clint Smith","external_urls":{"spotify":"https://open.spotify.com/user/clintsmith1"},"followers":{"href":null,"total":7},"href":"https://api.spotify.com/v1/users/clintsmith1","id":"clintsmith1","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee856520409d25d9cc210472a0fd","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b826520409d25d9cc210472a0fd","width":64}],"type":"user","uri":"spotify:user:clintsmith1"} Feb 10 14:51:24 volumio volumio[10181]: info: Spotify Successfully logged in Feb 10 14:51:24 volumio volumio[10181]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 14:51:24 volumio volumio[10181]: info: [1770756684199] CoreMusicLibrary::Adding element Spotify Feb 10 14:51:24 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 14:51:24 volumio volumio[10181]: Cannot find translation for source Bandcamp Discover Feb 10 14:51:24 volumio volumio[10181]: Cannot find translation for source SoundCloud Feb 10 14:51:24 volumio volumio[10181]: Cannot find translation for source YouTube2 Feb 10 14:51:24 volumio volumio[10181]: Cannot find translation for source YouTube Music Feb 10 14:51:24 volumio volumio[10181]: Cannot find translation for source Podcast Feb 10 14:51:24 volumio volumio[10181]: Cannot find translation for source Volusonic Feb 10 14:51:24 volumio volumio[10181]: Cannot find translation for source Spotify Feb 10 14:51:25 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:25 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:25 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 14:51:25 volumio volumio[10181]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 14:51:26 volumio volumio[10181]: info: go-librespot daemon successfully initialized Feb 10 14:51:26 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 10 14:51:26 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 10 14:51:26 volumio systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 10 14:51:27 volumio sudo[10525]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:27 volumio volumio[10181]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 14:51:27 volumio sudo[10551]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 14:51:27 volumio sudo[10551]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 134. Feb 10 14:51:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:51:27 volumio sudo[10551]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:27 volumio volumio[10181]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl stop squeezelite || true Feb 10 14:51:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:51:27 volumio go-librespot[10561]: go-librespot daemon starting... Feb 10 14:51:27 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 14:51:27 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 14:51:27 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 14:51:27 volumio systemd[1]: shairport-sync.service: Consumed 1.602s CPU time. Feb 10 14:51:27 volumio go-librespot[10569]: time="2026-02-10T14:51:27-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:51:27 volumio go-librespot[10569]: time="2026-02-10T14:51:27-06:00" level=debug msg="app state loaded" Feb 10 14:51:27 volumio go-librespot[10569]: time="2026-02-10T14:51:27-06:00" level=debug msg="stored credentials not found" Feb 10 14:51:27 volumio go-librespot[10569]: time="2026-02-10T14:51:27-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:51:27 volumio sudo[10568]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop squeezelite Feb 10 14:51:27 volumio sudo[10568]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:27 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 14:51:27 volumio sudo[10528]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:27 volumio systemd[1]: Stopping squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 10 14:51:27 volumio volumio[10181]: info: Shairport-Sync Started Feb 10 14:51:27 volumio systemd[1]: squeezelite.service: Deactivated successfully. Feb 10 14:51:27 volumio systemd[1]: Stopped squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 10 14:51:27 volumio sudo[10568]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:27 volumio go-librespot[10569]: time="2026-02-10T14:51:27-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 14:51:27 volumio go-librespot[10569]: time="2026-02-10T14:51:27-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 14:51:27 volumio go-librespot[10569]: time="2026-02-10T14:51:27-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 14:51:27 volumio go-librespot[10569]: time="2026-02-10T14:51:27-06:00" level=info msg="zeroconf server listening on port 45867" Feb 10 14:51:28 volumio go-librespot[10569]: time="2026-02-10T14:51:28-06:00" level=debug msg="obtained new client token: AADgoawXWwGti6DWy/e4mw+M5/AU+goXPFBTRFMEh4Ij1r1TGbR99TTz6N8fgWAMFlWXb7XqqYJgfqRKpn20wd76m3dAp68aStlrgqj6J9OJdvpvrKrbAC0pb6bssf0MXvl5gAYF90xQqVeSX2bmG4hzzumxGcMKW74mIb1xIYsbhZ0KAhwMvS9P+gXNF+rG5BaNH0RHwA8Z95I2Pg+1FF9J2gxFbxy7KJJl+b2Bmfp6ebWnxYnTaLM=" Feb 10 14:51:28 volumio go-librespot[10569]: time="2026-02-10T14:51:28-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 14:51:28 volumio go-librespot[10569]: time="2026-02-10T14:51:28-06:00" level=debug msg="completed keyexchange" Feb 10 14:51:28 volumio go-librespot[10569]: time="2026-02-10T14:51:28-06:00" level=debug msg="completed challenge" Feb 10 14:51:28 volumio go-librespot[10569]: time="2026-02-10T14:51:28-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:51:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:51:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:51:28 volumio volumio[10181]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 14:51:28 volumio sudo[10594]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 14:51:28 volumio sudo[10594]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:28 volumio sudo[10594]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:28 volumio volumio[10181]: info: [squeezelite_mc] Executing rm /tmp/squeezelite.log Feb 10 14:51:28 volumio sudo[10598]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm /tmp/squeezelite.log Feb 10 14:51:28 volumio sudo[10598]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:28 volumio sudo[10598]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:28 volumio volumio[10181]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl start squeezelite || true Feb 10 14:51:28 volumio sudo[10601]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start squeezelite Feb 10 14:51:28 volumio sudo[10601]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:28 volumio systemd[1]: Starting squeezelite.service - Squeezelite lightweight headless Squeezebox emulator... Feb 10 14:51:28 volumio systemd[1]: Started squeezelite.service - Squeezelite lightweight headless Squeezebox emulator. Feb 10 14:51:28 volumio sudo[10601]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:29 volumio volumio[10181]: info: Initializing connection to go-librespot Websocket Feb 10 14:51:29 volumio volumio[10181]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 14:51:29 volumio volumio[10181]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 14:51:29 volumio sudo[10608]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 14:51:29 volumio sudo[10608]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:29 volumio sudo[10608]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:29 volumio volumio[10181]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 14:51:29 volumio sudo[10611]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 14:51:29 volumio sudo[10611]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:29 volumio sudo[10611]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:30 volumio kernel: hwmon hwmon1: Voltage normalised Feb 10 14:51:30 volumio volumio[10181]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 14:51:30 volumio sudo[10615]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 14:51:30 volumio sudo[10615]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:30 volumio sudo[10615]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:30 volumio mpd[10549]: 2026-02-10T14:51:30 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 10 14:51:30 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 10 14:51:30 volumio sudo[10397]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:30 volumio sudo[10501]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:30 volumio sudo[10407]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:30 volumio volumio[10181]: error: MPD error: The expression evaluated to a falsy value: Feb 10 14:51:30 volumio volumio[10181]: assert.ok(self.idling) Feb 10 14:51:30 volumio volumio[10181]: error: The expression evaluated to a falsy value: Feb 10 14:51:30 volumio volumio[10181]: assert.ok(self.idling) Feb 10 14:51:30 volumio volumio[10181]: error: MPD error: The expression evaluated to a falsy value: Feb 10 14:51:30 volumio volumio[10181]: assert.ok(self.idling) Feb 10 14:51:30 volumio volumio[10181]: error: The expression evaluated to a falsy value: Feb 10 14:51:30 volumio volumio[10181]: assert.ok(self.idling) Feb 10 14:51:30 volumio volumio[10181]: info: MPD running with PID10549 Feb 10 14:51:30 volumio volumio[10181]: ,establishing connection Feb 10 14:51:30 volumio volumio[10181]: error: updateQueue error: null Feb 10 14:51:30 volumio volumio[10181]: error: updateQueue error: null Feb 10 14:51:31 volumio volumio[10181]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 14:51:31 volumio sudo[10625]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 14:51:31 volumio sudo[10625]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:31 volumio sudo[10625]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:31 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Feb 10 14:51:31 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Feb 10 14:51:31 volumio systemd[1]: welcome.service: Deactivated successfully. Feb 10 14:51:31 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Feb 10 14:51:31 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Feb 10 14:51:31 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Feb 10 14:51:31 volumio welcome[10646]: Resolved ip:[1] 192.168.1.221 Feb 10 14:51:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 135. Feb 10 14:51:31 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Feb 10 14:51:31 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Feb 10 14:51:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:51:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:51:31 volumio go-librespot[10651]: go-librespot daemon starting... Feb 10 14:51:31 volumio go-librespot[10652]: time="2026-02-10T14:51:31-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:51:31 volumio go-librespot[10652]: time="2026-02-10T14:51:31-06:00" level=debug msg="app state loaded" Feb 10 14:51:31 volumio go-librespot[10652]: time="2026-02-10T14:51:31-06:00" level=debug msg="stored credentials not found" Feb 10 14:51:31 volumio go-librespot[10652]: time="2026-02-10T14:51:31-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:51:31 volumio go-librespot[10652]: time="2026-02-10T14:51:31-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 14:51:31 volumio go-librespot[10652]: time="2026-02-10T14:51:31-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 10 14:51:31 volumio go-librespot[10652]: time="2026-02-10T14:51:31-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 10 14:51:31 volumio go-librespot[10652]: time="2026-02-10T14:51:31-06:00" level=info msg="zeroconf server listening on port 38647" Feb 10 14:51:31 volumio volumio[10181]: info: [squeezelite_mc] Executing /usr/bin/sudo /bin/systemctl status squeezelite || true Feb 10 14:51:31 volumio sudo[10660]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl status squeezelite Feb 10 14:51:31 volumio sudo[10660]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:31 volumio go-librespot[10652]: time="2026-02-10T14:51:31-06:00" level=debug msg="obtained new client token: AACy+UQ7loogNF2gvSrelpHtP9+mhrYRBKjCHgJcfbQ8i7yihceCjjWgIeO3q/ChgWzUIHnEgc5AmnR1xFH9SF3xthBedSY04ZQW6KVQay+kaEAQw2ZLYU9LkgS3GAvmsPLCRbxEeVNK+gfgY3KZ4le3eHwxxoW3IM8/PiuDjR6wlbBidQ2BGB8bpNCgn9jPH5gRamQYnyO00JGCeYJ73dYwdGRlDWo7a3RctcHryrf4ibAjWBHDMWJuYQ==" Feb 10 14:51:31 volumio sudo[10660]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:31 volumio volumio[10181]: info: Completed starting Core Plugins Feb 10 14:51:31 volumio volumio[10181]: info: ------------------------------------------- Feb 10 14:51:31 volumio volumio[10181]: info: ----- MyVolumio plugins startup ---- Feb 10 14:51:31 volumio volumio[10181]: info: ------------------------------------------- Feb 10 14:51:31 volumio volumio[10181]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 10 14:51:31 volumio go-librespot[10652]: time="2026-02-10T14:51:31-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Feb 10 14:51:31 volumio go-librespot[10652]: time="2026-02-10T14:51:31-06:00" level=debug msg="connected to ap-guc3.spotify.com:443" Feb 10 14:51:31 volumio go-librespot[10652]: time="2026-02-10T14:51:31-06:00" level=debug msg="completed keyexchange" Feb 10 14:51:31 volumio go-librespot[10652]: time="2026-02-10T14:51:31-06:00" level=debug msg="completed challenge" Feb 10 14:51:31 volumio go-librespot[10652]: time="2026-02-10T14:51:31-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:51:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:51:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:51:32 volumio volumio[10181]: info: Initializing connection to go-librespot Websocket Feb 10 14:51:32 volumio volumio[10181]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 14:51:33 volumio sudo[10663]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 10 14:51:33 volumio sudo[10663]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:33 volumio sudo[10665]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 10 14:51:33 volumio sudo[10665]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:33 volumio sudo[10667]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 10 14:51:33 volumio sudo[10667]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 14:51:33 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Feb 10 14:51:33 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Feb 10 14:51:33 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Feb 10 14:51:33 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Feb 10 14:51:33 volumio sudo[10663]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:33 volumio mpd_monitor.sh[10671]: MPD Monitor Service: Starting MPD Monitor Service Feb 10 14:51:33 volumio sudo[10665]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:33 volumio sudo[10667]: pam_unix(sudo:session): session closed for user root Feb 10 14:51:33 volumio volumio[10181]: info: Successfully started MPD Monitor Feb 10 14:51:33 volumio volumio[10181]: info: Successfully started MPD Monitor Feb 10 14:51:33 volumio volumio[10181]: info: Successfully started MPD Monitor Feb 10 14:51:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 136. Feb 10 14:51:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:51:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:51:35 volumio go-librespot[10675]: go-librespot daemon starting... Feb 10 14:51:35 volumio go-librespot[10676]: time="2026-02-10T14:51:35-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:51:35 volumio go-librespot[10676]: time="2026-02-10T14:51:35-06:00" level=debug msg="app state loaded" Feb 10 14:51:35 volumio go-librespot[10676]: time="2026-02-10T14:51:35-06:00" level=debug msg="stored credentials not found" Feb 10 14:51:35 volumio go-librespot[10676]: time="2026-02-10T14:51:35-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:51:35 volumio volumio[10181]: info: Initializing connection to go-librespot Websocket Feb 10 14:51:35 volumio go-librespot[10676]: time="2026-02-10T14:51:35-06:00" level=debug msg="new websocket client" Feb 10 14:51:35 volumio volumio[10181]: info: Connection to go-librespot Websocket established Feb 10 14:51:35 volumio go-librespot[10676]: time="2026-02-10T14:51:35-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 14:51:35 volumio go-librespot[10676]: time="2026-02-10T14:51:35-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 10 14:51:35 volumio go-librespot[10676]: time="2026-02-10T14:51:35-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 10 14:51:35 volumio go-librespot[10676]: time="2026-02-10T14:51:35-06:00" level=info msg="zeroconf server listening on port 37393" Feb 10 14:51:35 volumio go-librespot[10676]: time="2026-02-10T14:51:35-06:00" level=debug msg="obtained new client token: AAAqiqx0jb7Sla1VplrgCzf775PjsRaXAsyBlAdf8L1WV/GX2Zem73Yw9jbW9kztK6Yddh1NcjBw4OtXSHVrFtmCFKwG4jI+ywbxzsQe/39G7rx1/FiUCTIpeH60gdyaZxdFXllr/T4y9hGja3YjXZWZMy5HwiZmM5AbKPbn0+7yvn/ijhCkK+BW6+LbA48jzAtnNwZXhhWaxAEydCq1bMfCK2DA8BTtzuUed37YrhmkdV6ab7duDdxoGA==" Feb 10 14:51:35 volumio go-librespot[10676]: time="2026-02-10T14:51:35-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 14:51:35 volumio go-librespot[10676]: time="2026-02-10T14:51:35-06:00" level=debug msg="completed keyexchange" Feb 10 14:51:35 volumio go-librespot[10676]: time="2026-02-10T14:51:35-06:00" level=debug msg="completed challenge" Feb 10 14:51:35 volumio go-librespot[10676]: time="2026-02-10T14:51:35-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:51:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:51:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:51:35 volumio volumio[10181]: info: Connection to go-librespot Websocket closed Feb 10 14:51:38 volumio kernel: hwmon hwmon1: Undervoltage detected! Feb 10 14:51:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 137. Feb 10 14:51:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:51:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 14:51:38 volumio go-librespot[10699]: go-librespot daemon starting... Feb 10 14:51:38 volumio go-librespot[10700]: time="2026-02-10T14:51:38-06:00" level=info msg="running go-librespot 0.4.0" Feb 10 14:51:38 volumio go-librespot[10700]: time="2026-02-10T14:51:38-06:00" level=debug msg="app state loaded" Feb 10 14:51:38 volumio go-librespot[10700]: time="2026-02-10T14:51:38-06:00" level=debug msg="stored credentials not found" Feb 10 14:51:38 volumio go-librespot[10700]: time="2026-02-10T14:51:38-06:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 14:51:39 volumio go-librespot[10700]: time="2026-02-10T14:51:39-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 14:51:39 volumio go-librespot[10700]: time="2026-02-10T14:51:39-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 14:51:39 volumio go-librespot[10700]: time="2026-02-10T14:51:39-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 14:51:39 volumio go-librespot[10700]: time="2026-02-10T14:51:39-06:00" level=info msg="zeroconf server listening on port 42799" Feb 10 14:51:39 volumio go-librespot[10700]: time="2026-02-10T14:51:39-06:00" level=debug msg="obtained new client token: AAAqMcBmbjmd3xxHOXLtCxZ8ahyUBoYESL9wO2AydyyEksD30WXJD7JeaIBbLCPiX8UnRITgWhV3l1EkOP43+PcTox0kNOPZdft85V08DpiFBd9rqjTRmOixbk3kjYJeHEnBHeQ2vOYmyoTEDraN4Stvyt4C4GSU4bO3Nqvf34zPXt7lwWt+pQBF9G++atzbvV5/cYy3/b8Foabkr+QVeiNTi8HRmxZSebBtwIYiv1llGUawrT0tY1tMYQ==" Feb 10 14:51:39 volumio go-librespot[10700]: time="2026-02-10T14:51:39-06:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Feb 10 14:51:39 volumio go-librespot[10700]: time="2026-02-10T14:51:39-06:00" level=debug msg="connected to ap-guc3.spotify.com:443" Feb 10 14:51:39 volumio go-librespot[10700]: time="2026-02-10T14:51:39-06:00" level=debug msg="completed keyexchange" Feb 10 14:51:39 volumio go-librespot[10700]: time="2026-02-10T14:51:39-06:00" level=debug msg="completed challenge" Feb 10 14:51:39 volumio go-librespot[10700]: time="2026-02-10T14:51:39-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 14:51:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 14:51:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 14:51:39 volumio volumio[10181]: info: Getting Spotify volume Feb 10 14:51:39 volumio volumio[10181]: info: Initializing connection to go-librespot Websocket Feb 10 14:51:39 volumio volumio[10181]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 14:51:39 volumio volumio[10181]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 14:51:39 volumio volumio[10181]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 10 14:51:39 volumio volumio[10181]: errno: -111, Feb 10 14:51:39 volumio volumio[10181]: code: 'ECONNREFUSED', Feb 10 14:51:39 volumio volumio[10181]: syscall: 'connect', Feb 10 14:51:39 volumio volumio[10181]: address: '127.0.0.1', Feb 10 14:51:39 volumio volumio[10181]: port: 9879, Feb 10 14:51:39 volumio volumio[10181]: response: undefined Feb 10 14:51:39 volumio volumio[10181]: } Feb 10 14:51:39 volumio volumio[10181]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 14:51:41 volumio sudo[10721]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-10 14:50' Feb 10 14:51:41 volumio sudo[10721]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="ac7dd5922ede329d1459d48b226ddc71f5209a2c" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="3441cddd43405c36fe444484553f10f2f5bc830b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Nov 13 11:04:27 UTC 2025" VOLUMIO_VERSION="4.069" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="7da8d6d9f8baf8621af4ec2af5a00f00"