-- Logs begin at Fri 2025-03-14 15:02:31 CET, end at Fri 2025-03-14 16:26:57 CET. --
Mar 14 16:25:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:25:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 984.
Mar 14 16:25:00 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:25:01 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:25:01 volumio go-librespot[30024]: Librespot-go daemon starting...
Mar 14 16:25:01 volumio go-librespot[30024]: time="2025-03-14T16:25:01+01:00" level=info msg="generated new device id: 1a30179685b3ec7a08683bf733e21c473caf409c"
Mar 14 16:25:01 volumio go-librespot[30024]: time="2025-03-14T16:25:01+01:00" level=debug msg="stored credentials not found"
Mar 14 16:25:01 volumio go-librespot[30024]: time="2025-03-14T16:25:01+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 14 16:25:01 volumio go-librespot[30024]: time="2025-03-14T16:25:01+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 14 16:25:01 volumio go-librespot[30024]: time="2025-03-14T16:25:01+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 14 16:25:01 volumio go-librespot[30024]: time="2025-03-14T16:25:01+01:00" level=debug msg="zeroconf server listening on port 40077"
Mar 14 16:25:01 volumio go-librespot[30024]: time="2025-03-14T16:25:01+01:00" level=debug msg="obtained new client token: AAAnnZl+Ki8ZExs0EW+7ll4uK9oYnKX2rEvYJZWksBoDL+hXz6JeHEa+DEOwewGbE5xos5/+s0ypmbh3vOM30DSDOUbvVkKiiuwT4F8cW4hDJKV/6OMw/qdJUj2MyIn0+rA1TOlEvuhHxoVkuCyyTSN4F7Ox3TTFwWvcFEBhK+9l5OL9gs+CfhUtq3nN0rJI9sh6u6o+6MncV51icfTWuv6v8Grl7AC9yuFaR5Ku3xE+b//HvmkGvpYUhEg="
Mar 14 16:25:01 volumio go-librespot[30024]: time="2025-03-14T16:25:01+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:25:01 volumio go-librespot[30024]: time="2025-03-14T16:25:01+01:00" level=debug msg="completed keyexchange"
Mar 14 16:25:01 volumio go-librespot[30024]: time="2025-03-14T16:25:01+01:00" level=debug msg="completed challenge"
Mar 14 16:25:01 volumio go-librespot[30024]: time="2025-03-14T16:25:01+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Mar 14 16:25:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:25:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:25:01 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:25:01 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:25:03 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 14 16:25:04 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:25:04 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:25:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:25:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 985.
Mar 14 16:25:04 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:25:05 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:25:05 volumio go-librespot[30034]: Librespot-go daemon starting...
Mar 14 16:25:05 volumio go-librespot[30034]: time="2025-03-14T16:25:05+01:00" level=info msg="generated new device id: 0c51824fb18209df3e36a8dc03b51de3b0e3d2cd"
Mar 14 16:25:05 volumio go-librespot[30034]: time="2025-03-14T16:25:05+01:00" level=debug msg="stored credentials not found"
Mar 14 16:25:05 volumio go-librespot[30034]: time="2025-03-14T16:25:05+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 14 16:25:05 volumio go-librespot[30034]: time="2025-03-14T16:25:05+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 14 16:25:05 volumio go-librespot[30034]: time="2025-03-14T16:25:05+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 14 16:25:05 volumio go-librespot[30034]: time="2025-03-14T16:25:05+01:00" level=debug msg="zeroconf server listening on port 45791"
Mar 14 16:25:05 volumio go-librespot[30034]: time="2025-03-14T16:25:05+01:00" level=debug msg="obtained new client token: AAA1A2li1Wv/VDRJqU36mygELYXd1gfAbTtTzl2CP0qarXJdmH25sVw8gjhIj4HCvPXztYqJfQheZd3iDGczxopBlymyKHgywIsJt2MdEVBgLQIUOzo6hdBh0EYWR/SCHLL4E8O2dB+unp0g5tlYG0cEnXoCNuw5aY09GbBRFXFZRJkvPkM3iraprSTUawcu+8yz2KPqKCfzkM9WTYIsNqPT+znSvzLicy3y+3L7vX1pkd4rRByMi6neXPU="
Mar 14 16:25:05 volumio go-librespot[30034]: time="2025-03-14T16:25:05+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:25:05 volumio go-librespot[30034]: time="2025-03-14T16:25:05+01:00" level=debug msg="completed keyexchange"
Mar 14 16:25:05 volumio go-librespot[30034]: time="2025-03-14T16:25:05+01:00" level=debug msg="completed challenge"
Mar 14 16:25:05 volumio go-librespot[30034]: time="2025-03-14T16:25:05+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Mar 14 16:25:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:25:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:25:07 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 14 16:25:07 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:25:07 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:25:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:25:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 986.
Mar 14 16:25:08 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:25:09 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:25:09 volumio go-librespot[30059]: Librespot-go daemon starting...
Mar 14 16:25:09 volumio go-librespot[30059]: time="2025-03-14T16:25:09+01:00" level=info msg="generated new device id: c2ffbcf7a9397b5389ba3655180c41e4881aeb30"
Mar 14 16:25:09 volumio go-librespot[30059]: time="2025-03-14T16:25:09+01:00" level=debug msg="stored credentials not found"
Mar 14 16:25:09 volumio go-librespot[30059]: time="2025-03-14T16:25:09+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 14 16:25:09 volumio go-librespot[30059]: time="2025-03-14T16:25:09+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 14 16:25:09 volumio go-librespot[30059]: time="2025-03-14T16:25:09+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 14 16:25:09 volumio go-librespot[30059]: time="2025-03-14T16:25:09+01:00" level=debug msg="zeroconf server listening on port 35609"
Mar 14 16:25:09 volumio go-librespot[30059]: time="2025-03-14T16:25:09+01:00" level=debug msg="obtained new client token: AABBjtRvHvsnjpDa+jF/hee5kUqKVAQPM39OhqZFM3iAwGPRCKoy9hZsrOTfWG0+F+tocIRusqQV2lonRXuqWHxen9Q2gdX6dh36tbVtJ5UeBKatxHL5jPat3RT6woKC2mDOeRbWG05fKeEcc8r+EXwb13kRQQsshboqr8h9LOlvpMflPdyMcs979yMPG1fKcvByV+vXAY65ofhx1TvZ9BIABZN7OZvpK2W2UQxnY9aHvHg5dTYyh9/1z4o="
Mar 14 16:25:09 volumio go-librespot[30059]: time="2025-03-14T16:25:09+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:25:09 volumio go-librespot[30059]: time="2025-03-14T16:25:09+01:00" level=debug msg="completed keyexchange"
Mar 14 16:25:09 volumio go-librespot[30059]: time="2025-03-14T16:25:09+01:00" level=debug msg="completed challenge"
Mar 14 16:25:09 volumio go-librespot[30059]: time="2025-03-14T16:25:09+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Mar 14 16:25:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:25:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:25:10 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:25:10 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:25:11 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 14 16:25:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:25:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 987.
Mar 14 16:25:12 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:25:13 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:25:13 volumio go-librespot[30075]: Librespot-go daemon starting...
Mar 14 16:25:13 volumio go-librespot[30075]: time="2025-03-14T16:25:13+01:00" level=info msg="generated new device id: b6dc13d3cf88b0d2007be945085e4c0bfd491bd4"
Mar 14 16:25:13 volumio go-librespot[30075]: time="2025-03-14T16:25:13+01:00" level=debug msg="stored credentials not found"
Mar 14 16:25:13 volumio go-librespot[30075]: time="2025-03-14T16:25:13+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 14 16:25:13 volumio go-librespot[30075]: time="2025-03-14T16:25:13+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 14 16:25:13 volumio go-librespot[30075]: time="2025-03-14T16:25:13+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 14 16:25:13 volumio go-librespot[30075]: time="2025-03-14T16:25:13+01:00" level=debug msg="zeroconf server listening on port 34295"
Mar 14 16:25:13 volumio go-librespot[30075]: time="2025-03-14T16:25:13+01:00" level=debug msg="obtained new client token: AADLremmZxKu1rxjYBArK++k1cJlFUIo/rn9+k/Y7a7dixKi2DNog4GWUx/R93jGzIu1LcfTf4wRNLmbejKHSa2OcosDNupI3Zfzzl7W/GHuv7f2ffvqkPzUL97YiEoeHEYU/b+nPjZzkZ65waSzNpUISRXi0kg1S5C0ujCKu54EsSO6OEK761en3DQ19kKt8tMuYU2X6AHROELHVbIC90PzjXRAz4p3agEo7ggJ765SncRPJLTq7SMOGHo="
Mar 14 16:25:13 volumio go-librespot[30075]: time="2025-03-14T16:25:13+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:25:13 volumio go-librespot[30075]: time="2025-03-14T16:25:13+01:00" level=debug msg="completed keyexchange"
Mar 14 16:25:13 volumio go-librespot[30075]: time="2025-03-14T16:25:13+01:00" level=debug msg="completed challenge"
Mar 14 16:25:13 volumio go-librespot[30075]: time="2025-03-14T16:25:13+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Mar 14 16:25:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:25:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:25:13 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:25:13 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:25:15 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 14 16:25:16 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:25:16 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:25:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:25:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 988.
Mar 14 16:25:16 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:25:17 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:25:17 volumio go-librespot[30085]: Librespot-go daemon starting...
Mar 14 16:25:17 volumio go-librespot[30085]: time="2025-03-14T16:25:17+01:00" level=info msg="generated new device id: 60adbf09bb54145ed27abcab546f57261cb77812"
Mar 14 16:25:17 volumio go-librespot[30085]: time="2025-03-14T16:25:17+01:00" level=debug msg="stored credentials not found"
Mar 14 16:25:17 volumio go-librespot[30085]: time="2025-03-14T16:25:17+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 14 16:25:17 volumio go-librespot[30085]: time="2025-03-14T16:25:17+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 14 16:25:17 volumio go-librespot[30085]: time="2025-03-14T16:25:17+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 14 16:25:17 volumio go-librespot[30085]: time="2025-03-14T16:25:17+01:00" level=debug msg="zeroconf server listening on port 41935"
Mar 14 16:25:17 volumio go-librespot[30085]: time="2025-03-14T16:25:17+01:00" level=debug msg="obtained new client token: AADhMv6NdDKs6b2w3oMWli3Oslie2LKSi7CT6TUoObsA0rvtDuqsKB6m10smhUbmTuBOYAh2d35e2Q75S8qOU1aSrviGYABUY1BrPEKFciWyE9SKjNnOlqVx/YxtKhBpvJP+QQpFeHSdQjXoq8cQJj0eRq5eyQLUdBX6ybOUvz+HSVPq4u7CTCeAxWrfN4RGmCAMGRA3HgVASc6cFVSUgx8dEIryOxC9gL4feRkzElUNXD4T0Cz/KpfKRzE="
Mar 14 16:25:17 volumio go-librespot[30085]: time="2025-03-14T16:25:17+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:25:17 volumio go-librespot[30085]: time="2025-03-14T16:25:17+01:00" level=debug msg="completed keyexchange"
Mar 14 16:25:17 volumio go-librespot[30085]: time="2025-03-14T16:25:17+01:00" level=debug msg="completed challenge"
Mar 14 16:25:17 volumio go-librespot[30085]: time="2025-03-14T16:25:17+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Mar 14 16:25:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:25:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:25:19 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 14 16:25:19 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:25:19 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:25:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:25:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 989.
Mar 14 16:25:20 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:25:21 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:25:21 volumio go-librespot[30115]: Librespot-go daemon starting...
Mar 14 16:25:21 volumio go-librespot[30115]: time="2025-03-14T16:25:21+01:00" level=info msg="generated new device id: 5cbbbd1f68c9b67b4df21139e1bda8d4bb1862dc"
Mar 14 16:25:21 volumio go-librespot[30115]: time="2025-03-14T16:25:21+01:00" level=debug msg="stored credentials not found"
Mar 14 16:25:21 volumio go-librespot[30115]: time="2025-03-14T16:25:21+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 14 16:25:21 volumio go-librespot[30115]: time="2025-03-14T16:25:21+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 14 16:25:21 volumio go-librespot[30115]: time="2025-03-14T16:25:21+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 14 16:25:21 volumio go-librespot[30115]: time="2025-03-14T16:25:21+01:00" level=debug msg="zeroconf server listening on port 41997"
Mar 14 16:25:21 volumio go-librespot[30115]: time="2025-03-14T16:25:21+01:00" level=debug msg="obtained new client token: AADlNa4csSEk8mOz8ZAHg+Pdr10Vy9uft9Ee/4RogBjpVAM9tQNl2w1S/60XzIUpEgCLCEfgpPKNMkQX2ckVtp0Op8mPJHTnErD44EP6zVqqyTj0hDG0Ze1yDrT2AVPEJ87tB2wd2d4pCEyIUQ0y+YmYta6mbxBrizFbzzlVFby46QO0TYHhQy1Wc+4o14Ci9Dkga5oAvdJg+E8xuOJkgUNH30TuazLlZMi1jZxbWjN1buhA5Bzrk4adlG4="
Mar 14 16:25:21 volumio go-librespot[30115]: time="2025-03-14T16:25:21+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:25:21 volumio go-librespot[30115]: time="2025-03-14T16:25:21+01:00" level=debug msg="completed keyexchange"
Mar 14 16:25:21 volumio go-librespot[30115]: time="2025-03-14T16:25:21+01:00" level=debug msg="completed challenge"
Mar 14 16:25:21 volumio go-librespot[30115]: time="2025-03-14T16:25:21+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Mar 14 16:25:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:25:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:25:22 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:25:22 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:25:23 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 14 16:25:24 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:25:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 990.
Mar 14 16:25:24 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:25:25 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:25:25 volumio go-librespot[30124]: Librespot-go daemon starting...
Mar 14 16:25:25 volumio go-librespot[30124]: time="2025-03-14T16:25:25+01:00" level=info msg="generated new device id: ada2c8d49bdd78cc8b6e9d9f67e126e57c296c38"
Mar 14 16:25:25 volumio go-librespot[30124]: time="2025-03-14T16:25:25+01:00" level=debug msg="stored credentials not found"
Mar 14 16:25:25 volumio go-librespot[30124]: time="2025-03-14T16:25:25+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 14 16:25:25 volumio go-librespot[30124]: time="2025-03-14T16:25:25+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 14 16:25:25 volumio go-librespot[30124]: time="2025-03-14T16:25:25+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 14 16:25:25 volumio go-librespot[30124]: time="2025-03-14T16:25:25+01:00" level=debug msg="zeroconf server listening on port 42243"
Mar 14 16:25:25 volumio go-librespot[30124]: time="2025-03-14T16:25:25+01:00" level=debug msg="obtained new client token: AACjtHZC6MBaLpIY4dtU7O+OqIqtfyQ6RtctzywS98VlZjlyr9GQIiy8kd5YJLE7k8dHBr/JJSsmp1u2ZjDII3P5X9dhY3yV52ntW7yHkYhgEF2IbpJgdjJlKBF3SYQzCIjtvn0LDyoEwLkxOLBSLzfea8vAa1v6oEPpkXLA2TniM//eEHecTPmU/sDULXmDJEVe3p9BejpLtJl2TDTNSRGlPdMBdLSlYOo5K9vJwmWBf3VsEAcQWmQ/6zI="
Mar 14 16:25:25 volumio go-librespot[30124]: time="2025-03-14T16:25:25+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:25:25 volumio go-librespot[30124]: time="2025-03-14T16:25:25+01:00" level=debug msg="completed keyexchange"
Mar 14 16:25:25 volumio go-librespot[30124]: time="2025-03-14T16:25:25+01:00" level=debug msg="completed challenge"
Mar 14 16:25:25 volumio go-librespot[30124]: time="2025-03-14T16:25:25+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Mar 14 16:25:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:25:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:25:25 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:25:25 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:25:28 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 14 16:25:28 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:25:28 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:25:28 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:25:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 991.
Mar 14 16:25:28 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:25:29 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:25:29 volumio go-librespot[30150]: Librespot-go daemon starting...
Mar 14 16:25:29 volumio go-librespot[30150]: time="2025-03-14T16:25:29+01:00" level=info msg="generated new device id: 27cfa772e524329ecede3e140a6c05e514a0a33b"
Mar 14 16:25:29 volumio go-librespot[30150]: time="2025-03-14T16:25:29+01:00" level=debug msg="stored credentials not found"
Mar 14 16:25:29 volumio go-librespot[30150]: time="2025-03-14T16:25:29+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 14 16:25:29 volumio go-librespot[30150]: time="2025-03-14T16:25:29+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 14 16:25:29 volumio go-librespot[30150]: time="2025-03-14T16:25:29+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 14 16:25:29 volumio go-librespot[30150]: time="2025-03-14T16:25:29+01:00" level=debug msg="zeroconf server listening on port 46213"
Mar 14 16:25:29 volumio go-librespot[30150]: time="2025-03-14T16:25:29+01:00" level=debug msg="obtained new client token: AAC3R+GMlaqSmxschv6RnSVy1Hs8sazh3tpKXci4yx+V+Ziwi4pqRWjm1CI9/4krGcIwHtNrHT4Zp2kvUDaby7Rom5z7O0f6xyEogJLo3+VE05OTP8hjpzH0KG1An5to3w0ga0kMw9v5+uDsOBnjOHFRNSYBsdEqzZjzLTc8eKiWT2YWxBrFdQlt6ERmj+qhLcFFwuyGLcMx9UAKV5oYNHtC7K4ERQqMth9TvfTf4It3iL0CbA0X3dtoWyo="
Mar 14 16:25:29 volumio go-librespot[30150]: time="2025-03-14T16:25:29+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:25:29 volumio go-librespot[30150]: time="2025-03-14T16:25:29+01:00" level=debug msg="completed keyexchange"
Mar 14 16:25:29 volumio go-librespot[30150]: time="2025-03-14T16:25:29+01:00" level=debug msg="completed challenge"
Mar 14 16:25:29 volumio go-librespot[30150]: time="2025-03-14T16:25:29+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Mar 14 16:25:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:25:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:25:31 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:25:31 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:25:32 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 14 16:25:32 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:25:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 992.
Mar 14 16:25:32 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:25:33 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:25:33 volumio go-librespot[30164]: Librespot-go daemon starting...
Mar 14 16:25:33 volumio go-librespot[30164]: time="2025-03-14T16:25:33+01:00" level=info msg="generated new device id: 1b5cc57de895e3238c916e7b4eaad2153ecddf03"
Mar 14 16:25:33 volumio go-librespot[30164]: time="2025-03-14T16:25:33+01:00" level=debug msg="stored credentials not found"
Mar 14 16:25:33 volumio go-librespot[30164]: time="2025-03-14T16:25:33+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 14 16:25:33 volumio go-librespot[30164]: time="2025-03-14T16:25:33+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 14 16:25:33 volumio go-librespot[30164]: time="2025-03-14T16:25:33+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 14 16:25:33 volumio go-librespot[30164]: time="2025-03-14T16:25:33+01:00" level=debug msg="zeroconf server listening on port 46317"
Mar 14 16:25:33 volumio go-librespot[30164]: time="2025-03-14T16:25:33+01:00" level=debug msg="obtained new client token: AAAcKtPJ1uQQ4ZQPQcs/7jSHSAoWEM3UoZ5m9vA6h/ncIYiSoppHTH8ATFm6L9d2/LvuTFYeGJLD6UDkt3rOKKfm6YdsMcCcjmd/dkgQHZWBsHfzKypLf7oySwxCgl96yIOS1Kvna6IZwpjDTieD2StpqaWMTLpxnp+u/UoqSS42+I50ZWl9YV9vgFoysmYy3iN5kXq+MQzobXtJa7QLGuD3nrtTY5EcjuHkDyB+wTTZZSE4xlIYxC8DqQE="
Mar 14 16:25:33 volumio go-librespot[30164]: time="2025-03-14T16:25:33+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:25:33 volumio go-librespot[30164]: time="2025-03-14T16:25:33+01:00" level=debug msg="completed keyexchange"
Mar 14 16:25:33 volumio go-librespot[30164]: time="2025-03-14T16:25:33+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed solving challenge: failed login: BadCredentials"
Mar 14 16:25:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:25:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:25:34 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:25:34 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:25:36 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 14 16:25:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:25:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 993.
Mar 14 16:25:36 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:25:36 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:25:36 volumio go-librespot[30173]: Librespot-go daemon starting...
Mar 14 16:25:36 volumio go-librespot[30173]: time="2025-03-14T16:25:36+01:00" level=info msg="generated new device id: a4d100135052c0d895f1b7486ec20e1b77a8e594"
Mar 14 16:25:36 volumio go-librespot[30173]: time="2025-03-14T16:25:36+01:00" level=debug msg="stored credentials not found"
Mar 14 16:25:36 volumio go-librespot[30173]: time="2025-03-14T16:25:36+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 14 16:25:36 volumio go-librespot[30173]: time="2025-03-14T16:25:36+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 14 16:25:36 volumio go-librespot[30173]: time="2025-03-14T16:25:36+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 14 16:25:36 volumio go-librespot[30173]: time="2025-03-14T16:25:36+01:00" level=debug msg="zeroconf server listening on port 33611"
Mar 14 16:25:36 volumio go-librespot[30173]: time="2025-03-14T16:25:36+01:00" level=debug msg="obtained new client token: AADuMfNsZ+HYQDO2TC7y/ird27lrCXmuXKF2Is64m7Smdi6BahR10Rja63sDfmX5qaVH8xmramOcPHyyhdeYBuCty4e2Si3dEX/vNei8AMvvKSNudqktIlHHzmYn7kK9PMBiacTp4pWuKGrKVM6fp2FhspJNTdlWwIId8vMiz5wlcjnrzem4Nj6vWl3JeKn7zquuapf1bcHczl8nGPfU3ulK6BynrVPuykXr11bTxGqP3uhnxUUTbLMgFWiqNQ=="
Mar 14 16:25:36 volumio go-librespot[30173]: time="2025-03-14T16:25:36+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:25:36 volumio go-librespot[30173]: time="2025-03-14T16:25:36+01:00" level=debug msg="completed keyexchange"
Mar 14 16:25:37 volumio go-librespot[30173]: time="2025-03-14T16:25:37+01:00" level=debug msg="completed challenge"
Mar 14 16:25:37 volumio go-librespot[30173]: time="2025-03-14T16:25:37+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Mar 14 16:25:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:25:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:25:37 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:25:37 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:25:40 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 14 16:25:40 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:25:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 994.
Mar 14 16:25:40 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:25:40 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:25:40 volumio go-librespot[30247]: Librespot-go daemon starting...
Mar 14 16:25:40 volumio go-librespot[30247]: time="2025-03-14T16:25:40+01:00" level=info msg="generated new device id: 970eba80c474990a49b7ddadfa0b13ad1137b652"
Mar 14 16:25:40 volumio go-librespot[30247]: time="2025-03-14T16:25:40+01:00" level=debug msg="stored credentials not found"
Mar 14 16:25:40 volumio go-librespot[30247]: time="2025-03-14T16:25:40+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 14 16:25:40 volumio go-librespot[30247]: time="2025-03-14T16:25:40+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 14 16:25:40 volumio go-librespot[30247]: time="2025-03-14T16:25:40+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 14 16:25:40 volumio go-librespot[30247]: time="2025-03-14T16:25:40+01:00" level=debug msg="zeroconf server listening on port 43817"
Mar 14 16:25:40 volumio go-librespot[30247]: time="2025-03-14T16:25:40+01:00" level=debug msg="obtained new client token: AABc3DEVQFt44GODmvU3QcgIVauxFldycaaPmbXYFPeVcqltata+QJlsHEOxEGXpt9AEw2IipjWwzJ2+9Oev+YTAME6E7Cw6lk95buhNRKCdtDATeoBl+gf31yizwW9u2PL8k1H3j1HSW4HxRIBrvajj7X804rQDO3J8gn0WywzkNyl6YaaMpwlI2hH4hMM4rdf0nQNZm7kD7bVYcGj5g0aCh/C9TYUxKw0cYFK+OTL9vXDfiofpv/gSCJk/rw=="
Mar 14 16:25:40 volumio go-librespot[30247]: time="2025-03-14T16:25:40+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:25:40 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:25:40 volumio go-librespot[30247]: time="2025-03-14T16:25:40+01:00" level=debug msg="new websocket client"
Mar 14 16:25:40 volumio volumio[1345]: info: Connection to go-librespot Websocket established
Mar 14 16:25:41 volumio go-librespot[30247]: time="2025-03-14T16:25:41+01:00" level=debug msg="completed keyexchange"
Mar 14 16:25:41 volumio go-librespot[30247]: time="2025-03-14T16:25:41+01:00" level=debug msg="completed challenge"
Mar 14 16:25:41 volumio go-librespot[30247]: time="2025-03-14T16:25:41+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Mar 14 16:25:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:25:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:25:41 volumio volumio[1345]: info: Connection to go-librespot Websocket closed
Mar 14 16:25:43 volumio volumio[1345]: info: Getting Spotify volume
Mar 14 16:25:43 volumio volumio[1345]: (node:1345) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:25:43 volumio volumio[1345]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16)
Mar 14 16:25:43 volumio volumio[1345]: (node:1345) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 71)
Mar 14 16:25:43 volumio volumio[1345]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9
Mar 14 16:25:43 volumio volumio[1345]: info: CoreCommandRouter::volumioGetState
Mar 14 16:25:43 volumio volumio[1345]: info: CorePlayQueue::getTrack 6
Mar 14 16:25:43 volumio volumio[1345]: SPOTIFY: RECEIVED VOLUMIO VOLUME 6
Mar 14 16:25:44 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 14 16:25:44 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:25:44 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:25:44 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:25:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 995.
Mar 14 16:25:44 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:25:45 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:25:45 volumio go-librespot[30255]: Librespot-go daemon starting...
Mar 14 16:25:45 volumio go-librespot[30255]: time="2025-03-14T16:25:45+01:00" level=info msg="generated new device id: 7b22172024c5b782b6ea3a7f8760a0a383f28bf1"
Mar 14 16:25:45 volumio go-librespot[30255]: time="2025-03-14T16:25:45+01:00" level=debug msg="stored credentials not found"
Mar 14 16:25:45 volumio go-librespot[30255]: time="2025-03-14T16:25:45+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 14 16:25:45 volumio go-librespot[30255]: time="2025-03-14T16:25:45+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 14 16:25:45 volumio go-librespot[30255]: time="2025-03-14T16:25:45+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 14 16:25:45 volumio go-librespot[30255]: time="2025-03-14T16:25:45+01:00" level=debug msg="zeroconf server listening on port 33741"
Mar 14 16:25:45 volumio go-librespot[30255]: time="2025-03-14T16:25:45+01:00" level=debug msg="obtained new client token: AAACA/P7tMR5uJDvYY5gEXR0NtoBpwekSmpKCodsr5thhH5RbAvcZCzZEeTSBgqJbq+xuYWFTeqvlJBbTdOtPS6+aJWXPS5KKoE1WZ7FBMasifdM6ll/eau0gGxrApS9kc42ug87sitHOOej93EC4quUiNUotZiA6sMWXrODT8b/xwgENpELN99NvG5WcYHAfGMKGIGWiqEJSnASbUefKQqD0dGeUyzi/Hqvfh21r60WLCN6sKuynwyKJrE="
Mar 14 16:25:45 volumio go-librespot[30255]: time="2025-03-14T16:25:45+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:25:45 volumio go-librespot[30255]: time="2025-03-14T16:25:45+01:00" level=debug msg="completed keyexchange"
Mar 14 16:25:45 volumio go-librespot[30255]: time="2025-03-14T16:25:45+01:00" level=debug msg="completed challenge"
Mar 14 16:25:45 volumio go-librespot[30255]: time="2025-03-14T16:25:45+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Mar 14 16:25:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:25:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:25:47 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:25:47 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:25:48 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 14 16:25:48 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:25:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 996.
Mar 14 16:25:48 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:25:49 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:25:49 volumio go-librespot[30281]: Librespot-go daemon starting...
Mar 14 16:25:49 volumio go-librespot[30281]: time="2025-03-14T16:25:49+01:00" level=info msg="generated new device id: 8b76319cc47f11cc69ba294b9907b7e3b46495d8"
Mar 14 16:25:49 volumio go-librespot[30281]: time="2025-03-14T16:25:49+01:00" level=debug msg="stored credentials not found"
Mar 14 16:25:49 volumio go-librespot[30281]: time="2025-03-14T16:25:49+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 14 16:25:49 volumio go-librespot[30281]: time="2025-03-14T16:25:49+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 14 16:25:49 volumio go-librespot[30281]: time="2025-03-14T16:25:49+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 14 16:25:49 volumio go-librespot[30281]: time="2025-03-14T16:25:49+01:00" level=debug msg="zeroconf server listening on port 35279"
Mar 14 16:25:49 volumio go-librespot[30281]: time="2025-03-14T16:25:49+01:00" level=debug msg="obtained new client token: AADlzh6BgZygOJ/eqTTiniwPxLcMMN6Ij3JVBVvMU3M1wjRd+1kMObpgUr68yTaeqGJZynVGcXq+4feoJfRnms/x1G48+MtvPvl91jxuekbcibGCbCStf4ygiNFBKHBS3jxLz8iRs4ur+yY731rVl0JuFd6q5FAygK9ktxReKMk1k2zMtSTcd0yhzPk391/3PSeXBkLtVji7vUPplcBUYUhhDfDXQc5XgmSojXFBlD3yhXDq7moDMfGIJco="
Mar 14 16:25:49 volumio go-librespot[30281]: time="2025-03-14T16:25:49+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:25:49 volumio go-librespot[30281]: time="2025-03-14T16:25:49+01:00" level=debug msg="completed keyexchange"
Mar 14 16:25:49 volumio go-librespot[30281]: time="2025-03-14T16:25:49+01:00" level=debug msg="completed challenge"
Mar 14 16:25:49 volumio go-librespot[30281]: time="2025-03-14T16:25:49+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Mar 14 16:25:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:25:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:25:50 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:25:50 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:25:52 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:25:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 997.
Mar 14 16:25:52 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:25:53 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:25:53 volumio go-librespot[30295]: Librespot-go daemon starting...
Mar 14 16:25:53 volumio go-librespot[30295]: time="2025-03-14T16:25:53+01:00" level=info msg="generated new device id: 38ef3372024a63cf3c3571d146c8eb624faf8530"
Mar 14 16:25:53 volumio go-librespot[30295]: time="2025-03-14T16:25:53+01:00" level=debug msg="stored credentials not found"
Mar 14 16:25:53 volumio go-librespot[30295]: time="2025-03-14T16:25:53+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 14 16:25:53 volumio go-librespot[30295]: time="2025-03-14T16:25:53+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 14 16:25:53 volumio go-librespot[30295]: time="2025-03-14T16:25:53+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 14 16:25:53 volumio go-librespot[30295]: time="2025-03-14T16:25:53+01:00" level=debug msg="zeroconf server listening on port 42945"
Mar 14 16:25:53 volumio go-librespot[30295]: time="2025-03-14T16:25:53+01:00" level=debug msg="obtained new client token: AACjFLbOMvRkvhlEaBbPwSahtLKFyao8NMKTz0E8BU0WTFNj2JrVTOUlmzNOzkk2W2RuXpkk/Zt4ZKPe4WkUt3GYZcS2xhyMRmtu1/Ask0z/hgBmEBAgHXea/XwI3s1IO/+9viPscBIzv85hLGNK+QzHZu3lWh/z2k2hOgeWHlUpkDiRFXlbqJ+9D1i+zK2Dd3FJCNvCKd9jZHw3eMjy8KphmdXH9xIfFcKKaXc+vHdZEgocQp9hQTNmryw="
Mar 14 16:25:53 volumio go-librespot[30295]: time="2025-03-14T16:25:53+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:25:53 volumio go-librespot[30295]: time="2025-03-14T16:25:53+01:00" level=debug msg="completed keyexchange"
Mar 14 16:25:53 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 14 16:25:53 volumio go-librespot[30295]: time="2025-03-14T16:25:53+01:00" level=debug msg="completed challenge"
Mar 14 16:25:53 volumio go-librespot[30295]: time="2025-03-14T16:25:53+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Mar 14 16:25:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:25:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:25:53 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:25:53 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:25:56 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:25:56 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:25:56 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:25:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 998.
Mar 14 16:25:56 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:25:57 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:25:57 volumio go-librespot[30303]: Librespot-go daemon starting...
Mar 14 16:25:57 volumio go-librespot[30303]: time="2025-03-14T16:25:57+01:00" level=info msg="generated new device id: fa2b58df0566da65e94d097e11253a517aca87cd"
Mar 14 16:25:57 volumio go-librespot[30303]: time="2025-03-14T16:25:57+01:00" level=debug msg="stored credentials not found"
Mar 14 16:25:57 volumio go-librespot[30303]: time="2025-03-14T16:25:57+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 14 16:25:57 volumio go-librespot[30303]: time="2025-03-14T16:25:57+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 14 16:25:57 volumio go-librespot[30303]: time="2025-03-14T16:25:57+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 14 16:25:57 volumio go-librespot[30303]: time="2025-03-14T16:25:57+01:00" level=debug msg="zeroconf server listening on port 40333"
Mar 14 16:25:57 volumio go-librespot[30303]: time="2025-03-14T16:25:57+01:00" level=debug msg="obtained new client token: AAAi6nkIFZKz8/tHiZhcIynmWr24NR/BjsVQJ2SBJc+JbhI1rtfzJJQU0YdWng7ap7qstFOqpCgr5hJ2K+YKUKyrOV1dXDzD0W2H1Fi7QlH7NTVifUGP/HSYg0PgtrjC8CldAmFU9LIgyEJic30oPrBUSLRUlCx3LaiMKExKv9ifULnoLuosjKF8nVRfvfbyemB1V3OjQdscrnzcIToin3XKC/7/m/SkaXR+80aBiOZzZwutDTDkimTHIpk="
Mar 14 16:25:57 volumio go-librespot[30303]: time="2025-03-14T16:25:57+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:25:57 volumio go-librespot[30303]: time="2025-03-14T16:25:57+01:00" level=debug msg="completed keyexchange"
Mar 14 16:25:57 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 14 16:25:57 volumio go-librespot[30303]: time="2025-03-14T16:25:57+01:00" level=debug msg="completed challenge"
Mar 14 16:25:57 volumio go-librespot[30303]: time="2025-03-14T16:25:57+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Mar 14 16:25:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:25:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:25:59 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:25:59 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:26:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:26:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 999.
Mar 14 16:26:00 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:26:01 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:26:01 volumio go-librespot[30335]: Librespot-go daemon starting...
Mar 14 16:26:01 volumio go-librespot[30335]: time="2025-03-14T16:26:01+01:00" level=info msg="generated new device id: 65f449bddce179548efb415363165e79991ac155"
Mar 14 16:26:01 volumio go-librespot[30335]: time="2025-03-14T16:26:01+01:00" level=debug msg="stored credentials not found"
Mar 14 16:26:01 volumio go-librespot[30335]: time="2025-03-14T16:26:01+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 14 16:26:01 volumio go-librespot[30335]: time="2025-03-14T16:26:01+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 14 16:26:01 volumio go-librespot[30335]: time="2025-03-14T16:26:01+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 14 16:26:01 volumio go-librespot[30335]: time="2025-03-14T16:26:01+01:00" level=debug msg="zeroconf server listening on port 40567"
Mar 14 16:26:01 volumio go-librespot[30335]: time="2025-03-14T16:26:01+01:00" level=debug msg="obtained new client token: AABEc41Br/+mtvzrNRCbF3zZHYXLeIWAgur8/LLsK+VasO8Uv032MyQGah+e5mV3ZX2Z+DhPjAANG8gapGMBaKqQxUzFg4D1FpSZN6755mGjbeZ/0mlfE1fIVF72KRbt5CZ9lC+zsUGzitWOgJ9Se/frDxrRDtMtwAarcZEden+/KXDsS6vGnc/PNwZHe5tWVUdXsog1N77hcyfTpiDBTEeytiqErQmZqWNyB4zy7Zltg4rujBkkUaG5qts="
Mar 14 16:26:01 volumio go-librespot[30335]: time="2025-03-14T16:26:01+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:26:01 volumio go-librespot[30335]: time="2025-03-14T16:26:01+01:00" level=debug msg="completed keyexchange"
Mar 14 16:26:01 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 14 16:26:01 volumio go-librespot[30335]: time="2025-03-14T16:26:01+01:00" level=debug msg="completed challenge"
Mar 14 16:26:01 volumio go-librespot[30335]: time="2025-03-14T16:26:01+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Mar 14 16:26:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:26:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:26:01 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb
Mar 14 16:26:01 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand update
Mar 14 16:26:01 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:01 volumio volumio[1345]: info:
Mar 14 16:26:01 volumio volumio[1345]: ---------------------------- MPD announces state update: update
Mar 14 16:26:01 volumio volumio[1345]: info: sendMpdCommand update took 1 milliseconds
Mar 14 16:26:01 volumio volumio[1345]: info: ControllerMpd::getState
Mar 14 16:26:01 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:01 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:01 volumio volumio[1345]: info:
Mar 14 16:26:01 volumio volumio[1345]: ---------------------------- MPD announces state update: update
Mar 14 16:26:01 volumio volumio[1345]: info: ControllerMpd::getState
Mar 14 16:26:01 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:01 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:01 volumio volumio[1345]: info:
Mar 14 16:26:01 volumio volumio[1345]: ---------------------------- MPD announces state update: update
Mar 14 16:26:01 volumio volumio[1345]: info: ControllerMpd::getState
Mar 14 16:26:01 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:01 volumio volumio[1345]: info: sendMpdCommand status took 3 milliseconds
Mar 14 16:26:01 volumio volumio[1345]: info: sendMpdCommand status took 2 milliseconds
Mar 14 16:26:01 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:01 volumio volumio[1345]: info: Command Router : Notfying DB Updatetrue
Mar 14 16:26:01 volumio volumio[1345]: info: CoreCommandRouter::Close All Modals sent
Mar 14 16:26:01 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:01 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 14 16:26:01 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:01 volumio volumio[1345]: info: Command Router : Notfying DB Updatetrue
Mar 14 16:26:01 volumio volumio[1345]: info: CoreCommandRouter::Close All Modals sent
Mar 14 16:26:01 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:01 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 14 16:26:01 volumio volumio[1345]: info: sendMpdCommand status took 51 milliseconds
Mar 14 16:26:01 volumio volumio[1345]: info: sendMpdCommand status took 51 milliseconds
Mar 14 16:26:01 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:01 volumio volumio[1345]: info: Command Router : Notfying DB Updatetrue
Mar 14 16:26:01 volumio volumio[1345]: info: CoreCommandRouter::Close All Modals sent
Mar 14 16:26:01 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:01 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 14 16:26:02 volumio volumio[1345]: info: sendMpdCommand playlistinfo took 34 milliseconds
Mar 14 16:26:02 volumio volumio[1345]: info: sendMpdCommand playlistinfo took 19 milliseconds
Mar 14 16:26:02 volumio volumio[1345]: info: sendMpdCommand playlistinfo took 5 milliseconds
Mar 14 16:26:02 volumio volumio[1345]: verbose: ControllerMpd::parseTrackInfo
Mar 14 16:26:02 volumio volumio[1345]: verbose: ControllerMpd::parseTrackInfo
Mar 14 16:26:02 volumio volumio[1345]: verbose: ControllerMpd::parseTrackInfo
Mar 14 16:26:02 volumio volumio[1345]: info: ControllerMpd::pushState
Mar 14 16:26:02 volumio volumio[1345]: info: CoreCommandRouter::servicePushState
Mar 14 16:26:02 volumio volumio[1345]: info: CorePlayQueue::getTrack 6
Mar 14 16:26:02 volumio volumio[1345]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":169928,"duration":174,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"160 Kbps","isStreaming":false,"title":"El solitario","artist":"Los Pakines","album":"Exitos de Oro","uri":"INTERNAL/Los Pakines/Exitos de Oro/07 El solitario.mp3","trackType":"mp3"}
Mar 14 16:26:02 volumio volumio[1345]: verbose: CURRENT POSITION 6
Mar 14 16:26:02 volumio volumio[1345]: info: CoreStateMachine::syncState stateService pause
Mar 14 16:26:02 volumio volumio[1345]: info: CoreStateMachine::syncState currentStatus pause
Mar 14 16:26:02 volumio volumio[1345]: info: CoreStateMachine::pushState
Mar 14 16:26:02 volumio volumio[1345]: info: CorePlayQueue::getTrack 6
Mar 14 16:26:02 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 14 16:26:02 volumio volumio[1345]: info: CoreCommandRouter::volumioPushState
Mar 14 16:26:02 volumio volumio[1345]: info: CoreStateMachine::stPlaybackTimer
Mar 14 16:26:02 volumio volumio[1345]: info: ControllerMpd::pushState
Mar 14 16:26:02 volumio volumio[1345]: info: CoreCommandRouter::servicePushState
Mar 14 16:26:02 volumio volumio[1345]: info: CorePlayQueue::getTrack 6
Mar 14 16:26:02 volumio volumio[1345]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":169928,"duration":174,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"160 Kbps","isStreaming":false,"title":"El solitario","artist":"Los Pakines","album":"Exitos de Oro","uri":"INTERNAL/Los Pakines/Exitos de Oro/07 El solitario.mp3","trackType":"mp3"}
Mar 14 16:26:02 volumio volumio[1345]: verbose: CURRENT POSITION 6
Mar 14 16:26:02 volumio volumio[1345]: info: CoreStateMachine::syncState stateService pause
Mar 14 16:26:02 volumio volumio[1345]: info: CoreStateMachine::syncState currentStatus pause
Mar 14 16:26:02 volumio volumio[1345]: info: CoreStateMachine::pushState
Mar 14 16:26:02 volumio volumio[1345]: info: CorePlayQueue::getTrack 6
Mar 14 16:26:02 volumio volumio[1345]: info: CoreCommandRouter::volumioPushState
Mar 14 16:26:02 volumio volumio[1345]: info: CoreStateMachine::stPlaybackTimer
Mar 14 16:26:02 volumio volumio[1345]: info: ControllerMpd::pushState
Mar 14 16:26:02 volumio volumio[1345]: info: CoreCommandRouter::servicePushState
Mar 14 16:26:02 volumio volumio[1345]: info: CorePlayQueue::getTrack 6
Mar 14 16:26:02 volumio volumio[1345]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":169928,"duration":174,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"160 Kbps","isStreaming":false,"title":"El solitario","artist":"Los Pakines","album":"Exitos de Oro","uri":"INTERNAL/Los Pakines/Exitos de Oro/07 El solitario.mp3","trackType":"mp3"}
Mar 14 16:26:02 volumio volumio[1345]: verbose: CURRENT POSITION 6
Mar 14 16:26:02 volumio volumio[1345]: info: CoreStateMachine::syncState stateService pause
Mar 14 16:26:02 volumio volumio[1345]: info: CoreStateMachine::syncState currentStatus pause
Mar 14 16:26:02 volumio volumio[1345]: info: CoreStateMachine::pushState
Mar 14 16:26:02 volumio volumio[1345]: info: CorePlayQueue::getTrack 6
Mar 14 16:26:02 volumio volumio[1345]: info: CoreCommandRouter::volumioPushState
Mar 14 16:26:02 volumio volumio[1345]: info: CoreStateMachine::stPlaybackTimer
Mar 14 16:26:02 volumio volumio[1345]: info: ------------------------------ 76ms
Mar 14 16:26:02 volumio volumio[1345]: info: ------------------------------ 75ms
Mar 14 16:26:02 volumio volumio[1345]: info: ------------------------------ 75ms
Mar 14 16:26:02 volumio volumio[1345]: SPOTIFY: RECEIVED VOLUMIO VOLUME 6
Mar 14 16:26:02 volumio volumio[1345]: SPOTIFY: RECEIVED VOLUMIO VOLUME 6
Mar 14 16:26:02 volumio volumio[1345]: SPOTIFY: RECEIVED VOLUMIO VOLUME 6
Mar 14 16:26:02 volumio volumio[1345]: info: MPD Database updated - AlbumList cache refreshed
Mar 14 16:26:02 volumio volumio[1345]: info:
Mar 14 16:26:02 volumio volumio[1345]: ---------------------------- MPD announces state update: database
Mar 14 16:26:02 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:02 volumio volumio[1345]: info:
Mar 14 16:26:02 volumio volumio[1345]: ---------------------------- MPD announces state update: update
Mar 14 16:26:02 volumio volumio[1345]: info: ControllerMpd::getState
Mar 14 16:26:02 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:02 volumio volumio[1345]: info: ControllerMpd::getState
Mar 14 16:26:02 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:02 volumio volumio[1345]: info: MPD Database updated - AlbumList cache refreshed
Mar 14 16:26:02 volumio volumio[1345]: info:
Mar 14 16:26:02 volumio volumio[1345]: ---------------------------- MPD announces state update: database
Mar 14 16:26:02 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:02 volumio volumio[1345]: info:
Mar 14 16:26:02 volumio volumio[1345]: ---------------------------- MPD announces state update: update
Mar 14 16:26:02 volumio volumio[1345]: info: ControllerMpd::getState
Mar 14 16:26:02 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:02 volumio volumio[1345]: info: ControllerMpd::getState
Mar 14 16:26:02 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:02 volumio volumio[1345]: info: MPD Database updated - AlbumList cache refreshed
Mar 14 16:26:02 volumio volumio[1345]: info:
Mar 14 16:26:02 volumio volumio[1345]: ---------------------------- MPD announces state update: database
Mar 14 16:26:02 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:02 volumio volumio[1345]: info:
Mar 14 16:26:02 volumio volumio[1345]: ---------------------------- MPD announces state update: update
Mar 14 16:26:02 volumio volumio[1345]: info: ControllerMpd::getState
Mar 14 16:26:02 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:02 volumio volumio[1345]: info: ControllerMpd::getState
Mar 14 16:26:02 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:02 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:26:03 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:26:03 volumio volumio[1345]: info: sendMpdCommand status took 730 milliseconds
Mar 14 16:26:03 volumio volumio[1345]: info: sendMpdCommand status took 730 milliseconds
Mar 14 16:26:03 volumio volumio[1345]: info: sendMpdCommand status took 730 milliseconds
Mar 14 16:26:03 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:03 volumio volumio[1345]: info: Command Router : Notfying DB Updatefalse
Mar 14 16:26:03 volumio volumio[1345]: info: CoreCommandRouter::Close All Modals sent
Mar 14 16:26:03 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:03 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 14 16:26:03 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:03 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 14 16:26:03 volumio volumio[1345]: info: sendMpdCommand status took 1249 milliseconds
Mar 14 16:26:03 volumio volumio[1345]: info: sendMpdCommand status took 1249 milliseconds
Mar 14 16:26:03 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:03 volumio volumio[1345]: info: Command Router : Notfying DB Updatefalse
Mar 14 16:26:03 volumio volumio[1345]: info: CoreCommandRouter::Close All Modals sent
Mar 14 16:26:03 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:03 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 14 16:26:03 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:03 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 14 16:26:04 volumio volumio[1345]: info: sendMpdCommand status took 1743 milliseconds
Mar 14 16:26:04 volumio volumio[1345]: info: sendMpdCommand status took 1743 milliseconds
Mar 14 16:26:04 volumio volumio[1345]: info: sendMpdCommand status took 1743 milliseconds
Mar 14 16:26:04 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:04 volumio volumio[1345]: info: Command Router : Notfying DB Updatefalse
Mar 14 16:26:04 volumio volumio[1345]: info: CoreCommandRouter::Close All Modals sent
Mar 14 16:26:04 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:04 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 14 16:26:04 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:04 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 14 16:26:04 volumio volumio[1345]: info: sendMpdCommand playlistinfo took 1008 milliseconds
Mar 14 16:26:04 volumio volumio[1345]: info: sendMpdCommand playlistinfo took 1009 milliseconds
Mar 14 16:26:04 volumio volumio[1345]: verbose: ControllerMpd::parseTrackInfo
Mar 14 16:26:04 volumio volumio[1345]: verbose: ControllerMpd::parseTrackInfo
Mar 14 16:26:04 volumio volumio[1345]: info: ControllerMpd::pushState
Mar 14 16:26:04 volumio volumio[1345]: info: CoreCommandRouter::servicePushState
Mar 14 16:26:04 volumio volumio[1345]: info: CorePlayQueue::getTrack 6
Mar 14 16:26:04 volumio volumio[1345]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":169928,"duration":174,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"160 Kbps","isStreaming":false,"title":"El solitario","artist":"Los Pakines","album":"Exitos de Oro","uri":"INTERNAL/Los Pakines/Exitos de Oro/07 El solitario.mp3","trackType":"mp3"}
Mar 14 16:26:04 volumio volumio[1345]: verbose: CURRENT POSITION 6
Mar 14 16:26:04 volumio volumio[1345]: info: CoreStateMachine::syncState stateService pause
Mar 14 16:26:04 volumio volumio[1345]: info: CoreStateMachine::syncState currentStatus pause
Mar 14 16:26:04 volumio volumio[1345]: info: CoreStateMachine::pushState
Mar 14 16:26:04 volumio volumio[1345]: info: CorePlayQueue::getTrack 6
Mar 14 16:26:04 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 14 16:26:04 volumio volumio[1345]: info: CoreCommandRouter::volumioPushState
Mar 14 16:26:04 volumio volumio[1345]: info: CoreStateMachine::stPlaybackTimer
Mar 14 16:26:04 volumio volumio[1345]: info: ControllerMpd::pushState
Mar 14 16:26:04 volumio volumio[1345]: info: CoreCommandRouter::servicePushState
Mar 14 16:26:04 volumio volumio[1345]: info: CorePlayQueue::getTrack 6
Mar 14 16:26:04 volumio volumio[1345]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":169928,"duration":174,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"160 Kbps","isStreaming":false,"title":"El solitario","artist":"Los Pakines","album":"Exitos de Oro","uri":"INTERNAL/Los Pakines/Exitos de Oro/07 El solitario.mp3","trackType":"mp3"}
Mar 14 16:26:04 volumio volumio[1345]: verbose: CURRENT POSITION 6
Mar 14 16:26:04 volumio volumio[1345]: info: CoreStateMachine::syncState stateService pause
Mar 14 16:26:04 volumio volumio[1345]: info: CoreStateMachine::syncState currentStatus pause
Mar 14 16:26:04 volumio volumio[1345]: info: CoreStateMachine::pushState
Mar 14 16:26:04 volumio volumio[1345]: info: CorePlayQueue::getTrack 6
Mar 14 16:26:04 volumio volumio[1345]: info: CoreCommandRouter::volumioPushState
Mar 14 16:26:04 volumio volumio[1345]: info: CoreStateMachine::stPlaybackTimer
Mar 14 16:26:04 volumio volumio[1345]: info: ------------------------------ 1774ms
Mar 14 16:26:04 volumio volumio[1345]: info: ------------------------------ 1774ms
Mar 14 16:26:04 volumio volumio[1345]: info: sendMpdCommand playlistinfo took 489 milliseconds
Mar 14 16:26:04 volumio volumio[1345]: info: sendMpdCommand playlistinfo took 489 milliseconds
Mar 14 16:26:04 volumio volumio[1345]: info: sendMpdCommand playlistinfo took 8 milliseconds
Mar 14 16:26:04 volumio volumio[1345]: verbose: ControllerMpd::parseTrackInfo
Mar 14 16:26:04 volumio volumio[1345]: verbose: ControllerMpd::parseTrackInfo
Mar 14 16:26:04 volumio volumio[1345]: verbose: ControllerMpd::parseTrackInfo
Mar 14 16:26:04 volumio volumio[1345]: verbose: ControllerMpd::parseTrackInfo
Mar 14 16:26:04 volumio volumio[1345]: info: ControllerMpd::pushState
Mar 14 16:26:04 volumio volumio[1345]: info: CoreCommandRouter::servicePushState
Mar 14 16:26:04 volumio volumio[1345]: info: CorePlayQueue::getTrack 6
Mar 14 16:26:04 volumio volumio[1345]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":169928,"duration":174,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"160 Kbps","isStreaming":false,"title":"El solitario","artist":"Los Pakines","album":"Exitos de Oro","uri":"INTERNAL/Los Pakines/Exitos de Oro/07 El solitario.mp3","trackType":"mp3"}
Mar 14 16:26:04 volumio volumio[1345]: verbose: CURRENT POSITION 6
Mar 14 16:26:04 volumio volumio[1345]: info: CoreStateMachine::syncState stateService pause
Mar 14 16:26:04 volumio volumio[1345]: info: CoreStateMachine::syncState currentStatus pause
Mar 14 16:26:04 volumio volumio[1345]: info: CoreStateMachine::pushState
Mar 14 16:26:04 volumio volumio[1345]: info: CorePlayQueue::getTrack 6
Mar 14 16:26:04 volumio volumio[1345]: info: CoreCommandRouter::volumioPushState
Mar 14 16:26:04 volumio volumio[1345]: info: CoreStateMachine::stPlaybackTimer
Mar 14 16:26:04 volumio volumio[1345]: info: ControllerMpd::pushState
Mar 14 16:26:04 volumio volumio[1345]: info: CoreCommandRouter::servicePushState
Mar 14 16:26:04 volumio volumio[1345]: info: CorePlayQueue::getTrack 6
Mar 14 16:26:04 volumio volumio[1345]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":169928,"duration":174,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"160 Kbps","isStreaming":false,"title":"El solitario","artist":"Los Pakines","album":"Exitos de Oro","uri":"INTERNAL/Los Pakines/Exitos de Oro/07 El solitario.mp3","trackType":"mp3"}
Mar 14 16:26:04 volumio volumio[1345]: verbose: CURRENT POSITION 6
Mar 14 16:26:04 volumio volumio[1345]: info: CoreStateMachine::syncState stateService pause
Mar 14 16:26:04 volumio volumio[1345]: info: CoreStateMachine::syncState currentStatus pause
Mar 14 16:26:04 volumio volumio[1345]: info: CoreStateMachine::pushState
Mar 14 16:26:04 volumio volumio[1345]: info: CorePlayQueue::getTrack 6
Mar 14 16:26:04 volumio volumio[1345]: info: CoreCommandRouter::volumioPushState
Mar 14 16:26:04 volumio volumio[1345]: info: CoreStateMachine::stPlaybackTimer
Mar 14 16:26:04 volumio volumio[1345]: info: ControllerMpd::pushState
Mar 14 16:26:04 volumio volumio[1345]: info: CoreCommandRouter::servicePushState
Mar 14 16:26:04 volumio volumio[1345]: info: CorePlayQueue::getTrack 6
Mar 14 16:26:04 volumio volumio[1345]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":169928,"duration":174,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"160 Kbps","isStreaming":false,"title":"El solitario","artist":"Los Pakines","album":"Exitos de Oro","uri":"INTERNAL/Los Pakines/Exitos de Oro/07 El solitario.mp3","trackType":"mp3"}
Mar 14 16:26:04 volumio volumio[1345]: verbose: CURRENT POSITION 6
Mar 14 16:26:04 volumio volumio[1345]: info: CoreStateMachine::syncState stateService pause
Mar 14 16:26:04 volumio volumio[1345]: info: CoreStateMachine::syncState currentStatus pause
Mar 14 16:26:04 volumio volumio[1345]: info: CoreStateMachine::pushState
Mar 14 16:26:04 volumio volumio[1345]: info: CorePlayQueue::getTrack 6
Mar 14 16:26:04 volumio volumio[1345]: info: CoreCommandRouter::volumioPushState
Mar 14 16:26:04 volumio volumio[1345]: info: CoreStateMachine::stPlaybackTimer
Mar 14 16:26:04 volumio volumio[1345]: info: ControllerMpd::pushState
Mar 14 16:26:04 volumio volumio[1345]: info: CoreCommandRouter::servicePushState
Mar 14 16:26:04 volumio volumio[1345]: info: CorePlayQueue::getTrack 6
Mar 14 16:26:04 volumio volumio[1345]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":169928,"duration":174,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"160 Kbps","isStreaming":false,"title":"El solitario","artist":"Los Pakines","album":"Exitos de Oro","uri":"INTERNAL/Los Pakines/Exitos de Oro/07 El solitario.mp3","trackType":"mp3"}
Mar 14 16:26:04 volumio volumio[1345]: verbose: CURRENT POSITION 6
Mar 14 16:26:04 volumio volumio[1345]: info: CoreStateMachine::syncState stateService pause
Mar 14 16:26:04 volumio volumio[1345]: info: CoreStateMachine::syncState currentStatus pause
Mar 14 16:26:04 volumio volumio[1345]: info: CoreStateMachine::pushState
Mar 14 16:26:04 volumio volumio[1345]: info: CorePlayQueue::getTrack 6
Mar 14 16:26:04 volumio volumio[1345]: info: CoreCommandRouter::volumioPushState
Mar 14 16:26:04 volumio volumio[1345]: info: CoreStateMachine::stPlaybackTimer
Mar 14 16:26:04 volumio volumio[1345]: info: ------------------------------ 1780ms
Mar 14 16:26:04 volumio volumio[1345]: info: ------------------------------ 1780ms
Mar 14 16:26:04 volumio volumio[1345]: info: ------------------------------ 1779ms
Mar 14 16:26:04 volumio volumio[1345]: info: ------------------------------ 1779ms
Mar 14 16:26:04 volumio volumio[1345]: SPOTIFY: RECEIVED VOLUMIO VOLUME 6
Mar 14 16:26:04 volumio volumio[1345]: SPOTIFY: RECEIVED VOLUMIO VOLUME 6
Mar 14 16:26:04 volumio volumio[1345]: SPOTIFY: RECEIVED VOLUMIO VOLUME 6
Mar 14 16:26:04 volumio volumio[1345]: SPOTIFY: RECEIVED VOLUMIO VOLUME 6
Mar 14 16:26:04 volumio volumio[1345]: SPOTIFY: RECEIVED VOLUMIO VOLUME 6
Mar 14 16:26:04 volumio volumio[1345]: SPOTIFY: RECEIVED VOLUMIO VOLUME 6
Mar 14 16:26:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:26:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1000.
Mar 14 16:26:04 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:26:05 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:26:05 volumio go-librespot[30358]: Librespot-go daemon starting...
Mar 14 16:26:05 volumio go-librespot[30358]: time="2025-03-14T16:26:05+01:00" level=info msg="generated new device id: 911b1c6816e1beeef78edf44ba3241b55ca35ca5"
Mar 14 16:26:05 volumio go-librespot[30358]: time="2025-03-14T16:26:05+01:00" level=debug msg="stored credentials not found"
Mar 14 16:26:05 volumio go-librespot[30358]: time="2025-03-14T16:26:05+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 14 16:26:05 volumio go-librespot[30358]: time="2025-03-14T16:26:05+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 14 16:26:05 volumio go-librespot[30358]: time="2025-03-14T16:26:05+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 14 16:26:05 volumio go-librespot[30358]: time="2025-03-14T16:26:05+01:00" level=debug msg="zeroconf server listening on port 40331"
Mar 14 16:26:05 volumio go-librespot[30358]: time="2025-03-14T16:26:05+01:00" level=debug msg="obtained new client token: AABEJowpQFQlD8I80aKkIoD9qEQPR/BA5QFiowTKIQEl3LpMYycOKM5VaUBFo2jgrFk6OxKrrKWsGixIXEgCDDskFXMx/Wlcu1JiKMifUdLcO3xhS+FqNb0HPCUqWlnEQsVa6fWVLzNXiGrh0o5i7DOhCXRgyMvTaBEKX24AND+xagzEso8+ORBy66BAXCAaX6hI6CE9IjeClp4NsZwenxle95qQAHpC4EFeLRXR6JsxRE1qMNGkBl775pc="
Mar 14 16:26:05 volumio go-librespot[30358]: time="2025-03-14T16:26:05+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:26:05 volumio go-librespot[30358]: time="2025-03-14T16:26:05+01:00" level=debug msg="completed keyexchange"
Mar 14 16:26:05 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 14 16:26:05 volumio go-librespot[30358]: time="2025-03-14T16:26:05+01:00" level=debug msg="completed challenge"
Mar 14 16:26:05 volumio go-librespot[30358]: time="2025-03-14T16:26:05+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Mar 14 16:26:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:26:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:26:06 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:26:06 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:26:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:26:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1001.
Mar 14 16:26:08 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:26:09 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:26:09 volumio go-librespot[30383]: Librespot-go daemon starting...
Mar 14 16:26:09 volumio go-librespot[30383]: time="2025-03-14T16:26:09+01:00" level=info msg="generated new device id: 61b4e50853ea6381f6a92bca49a78a76389aae05"
Mar 14 16:26:09 volumio go-librespot[30383]: time="2025-03-14T16:26:09+01:00" level=debug msg="stored credentials not found"
Mar 14 16:26:09 volumio go-librespot[30383]: time="2025-03-14T16:26:09+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 14 16:26:09 volumio go-librespot[30383]: time="2025-03-14T16:26:09+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 14 16:26:09 volumio go-librespot[30383]: time="2025-03-14T16:26:09+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 14 16:26:09 volumio go-librespot[30383]: time="2025-03-14T16:26:09+01:00" level=debug msg="zeroconf server listening on port 36217"
Mar 14 16:26:09 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:26:09 volumio go-librespot[30383]: time="2025-03-14T16:26:09+01:00" level=debug msg="new websocket client"
Mar 14 16:26:09 volumio volumio[1345]: info: Connection to go-librespot Websocket established
Mar 14 16:26:09 volumio go-librespot[30383]: time="2025-03-14T16:26:09+01:00" level=debug msg="obtained new client token: AADvoH1gq1qrt26w02ADiVjpkS1MbroKB9AbwKPK4ZAfvt4uLCAOpxAIYXcH8XryjFVlscG10/aL4eWu2U/6g32FGYtI7hgwqphkUQCNStr0jcFm0F2weqltFnNH6om4KTNMhQZ6IE78E8j/6NWm3093vT3tFSW8/lrR0xEh1ZuCMxWK8O7RS3NkA9frd23f/QtGlvuLH4eGcMYDZbi6oYtAcmAvGmTm9h9FX52rNBu7QMjjzTiwsoy+eQ4="
Mar 14 16:26:09 volumio go-librespot[30383]: time="2025-03-14T16:26:09+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:26:09 volumio go-librespot[30383]: time="2025-03-14T16:26:09+01:00" level=debug msg="completed keyexchange"
Mar 14 16:26:09 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Mar 14 16:26:09 volumio volumio[1345]: info: CURURI: artists://
Mar 14 16:26:09 volumio volumio[1345]: info: Preload queue cleared
Mar 14 16:26:09 volumio go-librespot[30383]: time="2025-03-14T16:26:09+01:00" level=debug msg="completed challenge"
Mar 14 16:26:09 volumio go-librespot[30383]: time="2025-03-14T16:26:09+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Mar 14 16:26:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:26:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:26:09 volumio volumio[1345]: info: Connection to go-librespot Websocket closed
Mar 14 16:26:10 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 14 16:26:12 volumio volumio[1345]: info: Getting Spotify volume
Mar 14 16:26:12 volumio volumio[1345]: (node:1345) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:26:12 volumio volumio[1345]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16)
Mar 14 16:26:12 volumio volumio[1345]: (node:1345) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 72)
Mar 14 16:26:12 volumio volumio[1345]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9
Mar 14 16:26:12 volumio volumio[1345]: info: CoreCommandRouter::volumioGetState
Mar 14 16:26:12 volumio volumio[1345]: info: CorePlayQueue::getTrack 6
Mar 14 16:26:12 volumio volumio[1345]: SPOTIFY: RECEIVED VOLUMIO VOLUME 6
Mar 14 16:26:12 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:26:12 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:26:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:26:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1002.
Mar 14 16:26:12 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:26:13 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:26:13 volumio go-librespot[30397]: Librespot-go daemon starting...
Mar 14 16:26:13 volumio go-librespot[30397]: time="2025-03-14T16:26:13+01:00" level=info msg="generated new device id: d65f9e6fac781784c0a77b62a4f81bc8ba883784"
Mar 14 16:26:13 volumio go-librespot[30397]: time="2025-03-14T16:26:13+01:00" level=debug msg="stored credentials not found"
Mar 14 16:26:13 volumio go-librespot[30397]: time="2025-03-14T16:26:13+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 14 16:26:13 volumio go-librespot[30397]: time="2025-03-14T16:26:13+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 14 16:26:13 volumio go-librespot[30397]: time="2025-03-14T16:26:13+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 14 16:26:13 volumio go-librespot[30397]: time="2025-03-14T16:26:13+01:00" level=debug msg="zeroconf server listening on port 40657"
Mar 14 16:26:13 volumio go-librespot[30397]: time="2025-03-14T16:26:13+01:00" level=debug msg="obtained new client token: AACbx4tBsrXpvyln0bOoUEPJLvf82Q8vmfyleHVk/+TTbnmjPnjF1nQI4U3DFS2aVMiAkUitPpJ9k/SIVxmo/IQZWbVLA6U1Hlk0j6z54OevQw60RaqaVP/GEpiMa7YPbNhcW6ElAtpRAX2R8OQM38WTUPja7nDs3f9eV1sSJr8QCGR8MJLjSWRvKU7j96ZovWLkgFMSrdSnT3Se00YGgT6kKxUhm1xnURJnbkLjp81Dzek5W7HpP2QVFjI="
Mar 14 16:26:13 volumio go-librespot[30397]: time="2025-03-14T16:26:13+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:26:13 volumio volumio[1345]: Searching plugin music_service/mpd
Mar 14 16:26:13 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , search
Mar 14 16:26:13 volumio go-librespot[30397]: time="2025-03-14T16:26:13+01:00" level=debug msg="completed keyexchange"
Mar 14 16:26:13 volumio go-librespot[30397]: time="2025-03-14T16:26:13+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed solving challenge: failed login: BadCredentials"
Mar 14 16:26:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:26:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:26:13 volumio volumio[1345]: info: All search sources collected, pushing search results
Mar 14 16:26:13 volumio volumio[1345]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/volumio/app/plugins/miscellanea/albumart/icons/fa-tags.svg'
Mar 14 16:26:15 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 14 16:26:15 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:26:15 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:26:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:26:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1003.
Mar 14 16:26:16 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:26:16 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:26:16 volumio go-librespot[30405]: Librespot-go daemon starting...
Mar 14 16:26:16 volumio go-librespot[30405]: time="2025-03-14T16:26:16+01:00" level=info msg="generated new device id: 3c341d60ad0cf895870c5e79138d6be4fcd1c17d"
Mar 14 16:26:16 volumio go-librespot[30405]: time="2025-03-14T16:26:16+01:00" level=debug msg="stored credentials not found"
Mar 14 16:26:16 volumio go-librespot[30405]: time="2025-03-14T16:26:16+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 14 16:26:16 volumio go-librespot[30405]: time="2025-03-14T16:26:16+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 14 16:26:16 volumio go-librespot[30405]: time="2025-03-14T16:26:16+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 14 16:26:16 volumio go-librespot[30405]: time="2025-03-14T16:26:16+01:00" level=debug msg="zeroconf server listening on port 46517"
Mar 14 16:26:16 volumio go-librespot[30405]: time="2025-03-14T16:26:16+01:00" level=debug msg="obtained new client token: AADRMVPbAN4XvLNbKYGWU6USAlmhNGv1BtijnOGznN85Co5TfrLn2Qw1cCF28NfMtOhFltmkCBBaWX5gMpthK3gkFGVWVc0K16dOtAudc1ZVV+1ar1I7QLEPgTuHon09b3U9cl34UZzX4c6ZzkmMxfSYxy8QJJ3P75SdclzIXBaz69kkXGQkaire3pWnqMlYS8OpAkys9dyHH+acsq9FV47HHMELr+b8RwOjMGWPm5KBJ0iYOFztOmeMBfJCSA=="
Mar 14 16:26:16 volumio go-librespot[30405]: time="2025-03-14T16:26:16+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:26:16 volumio go-librespot[30405]: time="2025-03-14T16:26:16+01:00" level=debug msg="completed keyexchange"
Mar 14 16:26:17 volumio go-librespot[30405]: time="2025-03-14T16:26:17+01:00" level=debug msg="completed challenge"
Mar 14 16:26:17 volumio go-librespot[30405]: time="2025-03-14T16:26:17+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Mar 14 16:26:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:26:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:26:18 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:26:18 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:26:19 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 14 16:26:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:26:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1004.
Mar 14 16:26:20 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:26:20 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:26:20 volumio go-librespot[30435]: Librespot-go daemon starting...
Mar 14 16:26:20 volumio go-librespot[30435]: time="2025-03-14T16:26:20+01:00" level=info msg="generated new device id: a35873df8fcc96841f8974de1fbe9bced4bc3641"
Mar 14 16:26:20 volumio go-librespot[30435]: time="2025-03-14T16:26:20+01:00" level=debug msg="stored credentials not found"
Mar 14 16:26:20 volumio go-librespot[30435]: time="2025-03-14T16:26:20+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 14 16:26:20 volumio go-librespot[30435]: time="2025-03-14T16:26:20+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 14 16:26:20 volumio go-librespot[30435]: time="2025-03-14T16:26:20+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 14 16:26:20 volumio go-librespot[30435]: time="2025-03-14T16:26:20+01:00" level=debug msg="zeroconf server listening on port 36241"
Mar 14 16:26:20 volumio go-librespot[30435]: time="2025-03-14T16:26:20+01:00" level=debug msg="obtained new client token: AADQzsU2uaxFmwsiSRKMMhRh8W6tc0fQ6J/jQ9qFuPFlJTkMuMjpOIAxp5rqNWFdGgMhdp2VrVcmACXsx+ocG1osEwWb95O3Y7i5llxCk8SpSVs1qB3Nh4+54fh0tJwvHLt1cFugKOsRgbiBkYArdWcm0u9WcXA9a/XYM7X5fu+hXGvrLUKa6qGSWpkYTf+4mdCeZfMgSaYU/skb33AM9GZ2KAJLdF2lAueiMXEP3US34vVGZQLsW9szmUBpQg=="
Mar 14 16:26:20 volumio go-librespot[30435]: time="2025-03-14T16:26:20+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:26:20 volumio go-librespot[30435]: time="2025-03-14T16:26:20+01:00" level=debug msg="completed keyexchange"
Mar 14 16:26:21 volumio go-librespot[30435]: time="2025-03-14T16:26:21+01:00" level=debug msg="completed challenge"
Mar 14 16:26:21 volumio go-librespot[30435]: time="2025-03-14T16:26:21+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Mar 14 16:26:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:26:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:26:21 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:26:21 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:26:23 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 14 16:26:24 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:26:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1005.
Mar 14 16:26:24 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:26:24 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:26:24 volumio go-librespot[30444]: Librespot-go daemon starting...
Mar 14 16:26:24 volumio go-librespot[30444]: time="2025-03-14T16:26:24+01:00" level=info msg="generated new device id: 2e43a2272a5edb91c0ef244d182797fadadec9d8"
Mar 14 16:26:24 volumio go-librespot[30444]: time="2025-03-14T16:26:24+01:00" level=debug msg="stored credentials not found"
Mar 14 16:26:24 volumio go-librespot[30444]: time="2025-03-14T16:26:24+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 14 16:26:24 volumio go-librespot[30444]: time="2025-03-14T16:26:24+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 14 16:26:24 volumio go-librespot[30444]: time="2025-03-14T16:26:24+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 14 16:26:24 volumio go-librespot[30444]: time="2025-03-14T16:26:24+01:00" level=debug msg="zeroconf server listening on port 32907"
Mar 14 16:26:24 volumio go-librespot[30444]: time="2025-03-14T16:26:24+01:00" level=debug msg="obtained new client token: AADu9ILHT8XL2iDLTw1Vhpfx0gMjcOOjruuqYwhEpXxcpErmOEdRrxHpeUsWvkNO7l+t73H29OTIuoIE2RNgBVlKzOLX1OiZA6/tEJ64KtUTNrUMjJvrkFCiGFD0ehml6C8JrboEl8zsocLgUgSrBcE01ohsldAPRqrbJwTJxPb35YyDudYCOKEUhQVeLK+h9MAM7nXLQITUBDpba3MeB09/yfTzB7nF7z5fQr8hfNCLEVqm0YO3uwMnE3r28w=="
Mar 14 16:26:24 volumio go-librespot[30444]: time="2025-03-14T16:26:24+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:26:24 volumio go-librespot[30444]: time="2025-03-14T16:26:24+01:00" level=debug msg="completed keyexchange"
Mar 14 16:26:24 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:26:24 volumio go-librespot[30444]: time="2025-03-14T16:26:24+01:00" level=debug msg="new websocket client"
Mar 14 16:26:24 volumio volumio[1345]: info: Connection to go-librespot Websocket established
Mar 14 16:26:25 volumio go-librespot[30444]: time="2025-03-14T16:26:25+01:00" level=debug msg="completed challenge"
Mar 14 16:26:25 volumio go-librespot[30444]: time="2025-03-14T16:26:25+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Mar 14 16:26:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:26:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:26:25 volumio volumio[1345]: info: Connection to go-librespot Websocket closed
Mar 14 16:26:27 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 14 16:26:27 volumio volumio[1345]: info: Getting Spotify volume
Mar 14 16:26:27 volumio volumio[1345]: (node:1345) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:26:27 volumio volumio[1345]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16)
Mar 14 16:26:27 volumio volumio[1345]: (node:1345) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 73)
Mar 14 16:26:27 volumio volumio[1345]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9
Mar 14 16:26:27 volumio volumio[1345]: info: CoreCommandRouter::volumioGetState
Mar 14 16:26:27 volumio volumio[1345]: info: CorePlayQueue::getTrack 6
Mar 14 16:26:27 volumio volumio[1345]: SPOTIFY: RECEIVED VOLUMIO VOLUME 6
Mar 14 16:26:28 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:26:28 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:26:28 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:26:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1006.
Mar 14 16:26:28 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:26:28 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:26:28 volumio go-librespot[30470]: Librespot-go daemon starting...
Mar 14 16:26:28 volumio go-librespot[30470]: time="2025-03-14T16:26:28+01:00" level=info msg="generated new device id: 9244304529026d9aaaad5512c9fb93683d88d5b1"
Mar 14 16:26:28 volumio go-librespot[30470]: time="2025-03-14T16:26:28+01:00" level=debug msg="stored credentials not found"
Mar 14 16:26:28 volumio go-librespot[30470]: time="2025-03-14T16:26:28+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 14 16:26:28 volumio go-librespot[30470]: time="2025-03-14T16:26:28+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 14 16:26:28 volumio go-librespot[30470]: time="2025-03-14T16:26:28+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 14 16:26:28 volumio go-librespot[30470]: time="2025-03-14T16:26:28+01:00" level=debug msg="zeroconf server listening on port 37259"
Mar 14 16:26:28 volumio go-librespot[30470]: time="2025-03-14T16:26:28+01:00" level=debug msg="obtained new client token: AABkRaLJpVlpZkmq+Cmy5rvtY91MhWDfFE5I3+ki1KI2LaogZVX2nOJRc7WNIwEcaeKQs4B9Wm+fYJWhAd0b0KaVOKLsKSl5BJ35JmB4AW63PQ/iY1RrsRDlT7tjOCOuWNeGXDFDqQFSFTg+ga7qgrQ3IbUltxJ1buBIxExZOmHcsDWVCjNT8txlUS2LeMopS4XYJ2dZqPDgrVrP8CAV0TY3FnvOqRh3g9y6qgvMmsjRKEFqsX3OMlBlbjqMyg=="
Mar 14 16:26:28 volumio go-librespot[30470]: time="2025-03-14T16:26:28+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:26:28 volumio go-librespot[30470]: time="2025-03-14T16:26:28+01:00" level=debug msg="completed keyexchange"
Mar 14 16:26:29 volumio go-librespot[30470]: time="2025-03-14T16:26:29+01:00" level=debug msg="completed challenge"
Mar 14 16:26:29 volumio go-librespot[30470]: time="2025-03-14T16:26:29+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Mar 14 16:26:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:26:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:26:31 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:26:31 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:26:31 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 14 16:26:32 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:26:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1007.
Mar 14 16:26:32 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:26:32 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:26:32 volumio go-librespot[30485]: Librespot-go daemon starting...
Mar 14 16:26:32 volumio go-librespot[30485]: time="2025-03-14T16:26:32+01:00" level=info msg="generated new device id: 0f5a5683c02cd4c99e3553448d652351ee85c1df"
Mar 14 16:26:32 volumio go-librespot[30485]: time="2025-03-14T16:26:32+01:00" level=debug msg="stored credentials not found"
Mar 14 16:26:32 volumio go-librespot[30485]: time="2025-03-14T16:26:32+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 14 16:26:32 volumio go-librespot[30485]: time="2025-03-14T16:26:32+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 14 16:26:32 volumio go-librespot[30485]: time="2025-03-14T16:26:32+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 14 16:26:32 volumio go-librespot[30485]: time="2025-03-14T16:26:32+01:00" level=debug msg="zeroconf server listening on port 39481"
Mar 14 16:26:32 volumio go-librespot[30485]: time="2025-03-14T16:26:32+01:00" level=debug msg="obtained new client token: AADlB7HtCs9ICv9eKICYtfVqFjdG+rMsCi9jot28580y1JNpaSEWDXhcPTaWIAhas9pHSTMSb/H+0vReOVjjlfKP+j2u0fZBvlzf+cW8hntFPW16h6DbsB/c08C+HFHye1LJ9KKK4X91gyAtWNqgO+hTczbwom/gMo3aHmL2CfYZexcVkJtM4zXlvv0BN/WjpLGiqkwpghKohKsjOPW6yKXz+zsWsG+S6zSP6A0gW87V8LpfKcPbLnYc4LosJA=="
Mar 14 16:26:32 volumio go-librespot[30485]: time="2025-03-14T16:26:32+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:26:32 volumio go-librespot[30485]: time="2025-03-14T16:26:32+01:00" level=debug msg="completed keyexchange"
Mar 14 16:26:33 volumio go-librespot[30485]: time="2025-03-14T16:26:33+01:00" level=debug msg="completed challenge"
Mar 14 16:26:33 volumio go-librespot[30485]: time="2025-03-14T16:26:33+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Mar 14 16:26:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:26:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:26:34 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:26:34 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:26:35 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 14 16:26:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:26:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1008.
Mar 14 16:26:36 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:26:36 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:26:36 volumio go-librespot[30493]: Librespot-go daemon starting...
Mar 14 16:26:36 volumio go-librespot[30493]: time="2025-03-14T16:26:36+01:00" level=info msg="generated new device id: 1969798b2b94e515f1b8b26ecaf7d491d468a380"
Mar 14 16:26:36 volumio go-librespot[30493]: time="2025-03-14T16:26:36+01:00" level=debug msg="stored credentials not found"
Mar 14 16:26:36 volumio go-librespot[30493]: time="2025-03-14T16:26:36+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 14 16:26:36 volumio go-librespot[30493]: time="2025-03-14T16:26:36+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 14 16:26:36 volumio go-librespot[30493]: time="2025-03-14T16:26:36+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 14 16:26:36 volumio go-librespot[30493]: time="2025-03-14T16:26:36+01:00" level=debug msg="zeroconf server listening on port 39543"
Mar 14 16:26:36 volumio go-librespot[30493]: time="2025-03-14T16:26:36+01:00" level=debug msg="obtained new client token: AABbcMcZUnqq3xwVugZ60hBRXYzrPdglTvLSFquIQpcJrhQn3YDUfGU/eUZ964EUb3iGnmFffB6ig3xXevTM1Q9tqgaotKIZ8HqDhe4eAOH40SnCccZJ1vimluJfZEzBB6CVQHzOuqu97em+N7MZY54CxzG943yOUeB79W6JXRjzSOUoje9nILbgtIIU49nHpHC9jckD1PA5vKRAyJ8/LyPQPvkB3K4DlYSO9shvLZUBbLgsDsP8wkLpGZyTSg=="
Mar 14 16:26:36 volumio go-librespot[30493]: time="2025-03-14T16:26:36+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:26:36 volumio go-librespot[30493]: time="2025-03-14T16:26:36+01:00" level=debug msg="completed keyexchange"
Mar 14 16:26:37 volumio go-librespot[30493]: time="2025-03-14T16:26:37+01:00" level=debug msg="completed challenge"
Mar 14 16:26:37 volumio go-librespot[30493]: time="2025-03-14T16:26:37+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Mar 14 16:26:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:26:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:26:37 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:26:37 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:26:39 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 14 16:26:40 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:26:40 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:26:40 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:26:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1009.
Mar 14 16:26:40 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:26:40 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:26:40 volumio go-librespot[30567]: Librespot-go daemon starting...
Mar 14 16:26:40 volumio go-librespot[30567]: time="2025-03-14T16:26:40+01:00" level=info msg="generated new device id: 39ab1adbf94b040ed5d8bf8b42a8cca027f6ac37"
Mar 14 16:26:40 volumio go-librespot[30567]: time="2025-03-14T16:26:40+01:00" level=debug msg="stored credentials not found"
Mar 14 16:26:40 volumio go-librespot[30567]: time="2025-03-14T16:26:40+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 14 16:26:40 volumio go-librespot[30567]: time="2025-03-14T16:26:40+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 14 16:26:40 volumio go-librespot[30567]: time="2025-03-14T16:26:40+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 14 16:26:40 volumio go-librespot[30567]: time="2025-03-14T16:26:40+01:00" level=debug msg="zeroconf server listening on port 43447"
Mar 14 16:26:40 volumio go-librespot[30567]: time="2025-03-14T16:26:40+01:00" level=debug msg="obtained new client token: AADV/xpJwNKXabtgBbUxqFUrtllyZDClnz2TcwVsB//SdYATDA7lvrLf/9rNT8qpzE9M0CDGniluRw8sECxkCfl3t4BROsaI65Ua7FR+yMhnDghh9kMJN3HFihu8l14JQCLajpFjnTjoaEgGMDA60mwQe98vgV07sTVTcndpUODe4mk0yVbUe+kpzHV5zEwq2A7s30PKqF1wdSmEXStM9xKPlQ64OPoSG6i7NveGejDMpG3Ri2Rs9QIGCp5PYQ=="
Mar 14 16:26:40 volumio go-librespot[30567]: time="2025-03-14T16:26:40+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:26:40 volumio go-librespot[30567]: time="2025-03-14T16:26:40+01:00" level=debug msg="completed keyexchange"
Mar 14 16:26:41 volumio go-librespot[30567]: time="2025-03-14T16:26:41+01:00" level=debug msg="completed challenge"
Mar 14 16:26:41 volumio go-librespot[30567]: time="2025-03-14T16:26:41+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Mar 14 16:26:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:26:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:26:43 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:26:43 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:26:44 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 14 16:26:44 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:26:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1010.
Mar 14 16:26:44 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:26:44 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:26:44 volumio go-librespot[30575]: Librespot-go daemon starting...
Mar 14 16:26:44 volumio go-librespot[30575]: time="2025-03-14T16:26:44+01:00" level=info msg="generated new device id: 35f5bfee43ca447c82ae7416b91279c76f962b0f"
Mar 14 16:26:44 volumio go-librespot[30575]: time="2025-03-14T16:26:44+01:00" level=debug msg="stored credentials not found"
Mar 14 16:26:44 volumio go-librespot[30575]: time="2025-03-14T16:26:44+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 14 16:26:44 volumio go-librespot[30575]: time="2025-03-14T16:26:44+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 14 16:26:44 volumio go-librespot[30575]: time="2025-03-14T16:26:44+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 14 16:26:44 volumio go-librespot[30575]: time="2025-03-14T16:26:44+01:00" level=debug msg="zeroconf server listening on port 39479"
Mar 14 16:26:44 volumio go-librespot[30575]: time="2025-03-14T16:26:44+01:00" level=debug msg="obtained new client token: AABfhqqSZ7FIGwrN08cWZ8MFkWJqROXGjhcS/2cXQl9XfiIT1nA/HC263QrH7dwGFZyPEYEAG/0ZzAompwCVh3a4jZNOaSXoNttPJn12XV02yIROBQgZYmgzxWYmqBiqmhCxdECFg7v/O0I8zutKxL8Db2lPjEquXVyzwXLglfQXVShMuqb7KDqDbq+dfsJFD+e8nUgG8/R25op0Ocs+Vu7VJc/LQv3cqxa1ABgiiq1YFANt5pk3Q+V8kjdU3A=="
Mar 14 16:26:44 volumio go-librespot[30575]: time="2025-03-14T16:26:44+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:26:44 volumio go-librespot[30575]: time="2025-03-14T16:26:44+01:00" level=debug msg="completed keyexchange"
Mar 14 16:26:45 volumio go-librespot[30575]: time="2025-03-14T16:26:45+01:00" level=debug msg="completed challenge"
Mar 14 16:26:45 volumio go-librespot[30575]: time="2025-03-14T16:26:45+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Mar 14 16:26:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:26:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:26:46 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:26:46 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:26:48 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 14 16:26:48 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:26:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1011.
Mar 14 16:26:48 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:26:48 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:26:48 volumio go-librespot[30600]: Librespot-go daemon starting...
Mar 14 16:26:48 volumio go-librespot[30600]: time="2025-03-14T16:26:48+01:00" level=info msg="generated new device id: 16daaea8eb6e8241be6081e31d95350734f84a2c"
Mar 14 16:26:48 volumio go-librespot[30600]: time="2025-03-14T16:26:48+01:00" level=debug msg="stored credentials not found"
Mar 14 16:26:48 volumio go-librespot[30600]: time="2025-03-14T16:26:48+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 14 16:26:48 volumio go-librespot[30600]: time="2025-03-14T16:26:48+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 14 16:26:48 volumio go-librespot[30600]: time="2025-03-14T16:26:48+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 14 16:26:48 volumio go-librespot[30600]: time="2025-03-14T16:26:48+01:00" level=debug msg="zeroconf server listening on port 37523"
Mar 14 16:26:48 volumio go-librespot[30600]: time="2025-03-14T16:26:48+01:00" level=debug msg="obtained new client token: AACveM+sa0iFPiKOgDqiudrKTNZjw/EtVrshaF/WRn4AZQo79TKdCGxmDQ9s8SNdQD8hC0tqlFMiUkxIiBTn6OxL8xJyrVZOyGynfCip0wLn/O9GWPEB4TSXgN92UKzgdl//VJnQrjW/nZrIuMIwBQq5B++bF1gGpX9mcqYJLhFSxUebmt+hu/90n9/aHooSadWYwFSRZUguhTU7oSkWi3uxrFgmkleFB50PQ1l3yTZuZBhX+22sTa7MuYZPJg=="
Mar 14 16:26:48 volumio go-librespot[30600]: time="2025-03-14T16:26:48+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:26:48 volumio go-librespot[30600]: time="2025-03-14T16:26:48+01:00" level=debug msg="completed keyexchange"
Mar 14 16:26:49 volumio go-librespot[30600]: time="2025-03-14T16:26:49+01:00" level=debug msg="completed challenge"
Mar 14 16:26:49 volumio go-librespot[30600]: time="2025-03-14T16:26:49+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Mar 14 16:26:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:26:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:26:49 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:26:49 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:26:52 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:26:52 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:26:52 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 14 16:26:52 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:26:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1012.
Mar 14 16:26:52 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:26:52 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:26:52 volumio go-librespot[30615]: Librespot-go daemon starting...
Mar 14 16:26:52 volumio go-librespot[30615]: time="2025-03-14T16:26:52+01:00" level=info msg="generated new device id: f64ee23cd7846581332d09b5b0b22c6b0f497fe2"
Mar 14 16:26:52 volumio go-librespot[30615]: time="2025-03-14T16:26:52+01:00" level=debug msg="stored credentials not found"
Mar 14 16:26:52 volumio go-librespot[30615]: time="2025-03-14T16:26:52+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Mar 14 16:26:52 volumio go-librespot[30615]: time="2025-03-14T16:26:52+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Mar 14 16:26:52 volumio go-librespot[30615]: time="2025-03-14T16:26:52+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Mar 14 16:26:52 volumio go-librespot[30615]: time="2025-03-14T16:26:52+01:00" level=debug msg="zeroconf server listening on port 44131"
Mar 14 16:26:52 volumio go-librespot[30615]: time="2025-03-14T16:26:52+01:00" level=debug msg="obtained new client token: AABLpiBM+P+NRhBIOxpTlsJhMKZZiOlHKDu9SuKx2WSFqbEYNVAd0rlA5tpVKjAceFUwxcTcCaBuBmm16hQuGYl51mm+87Of+NNwdB3+yNzD+2AfZ6zqVmGqZPiOGNMsnWBc/mrU5octOPcCrEahozGGkemZaB/jAJ49s/Nzk13t2jPklLSR5N21qyx1Ql+jo0PLG31qdfB/0wiInV53fk9S3Pum7nxb2n9vEOGqNqDqCy596ju2GYezjCa9Cw=="
Mar 14 16:26:52 volumio go-librespot[30615]: time="2025-03-14T16:26:52+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:26:52 volumio go-librespot[30615]: time="2025-03-14T16:26:52+01:00" level=debug msg="completed keyexchange"
Mar 14 16:26:53 volumio go-librespot[30615]: time="2025-03-14T16:26:53+01:00" level=debug msg="completed challenge"
Mar 14 16:26:53 volumio go-librespot[30615]: time="2025-03-14T16:26:53+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Mar 14 16:26:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:26:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:26:55 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb
Mar 14 16:26:55 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand update
Mar 14 16:26:55 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:55 volumio volumio[1345]: info:
Mar 14 16:26:55 volumio volumio[1345]: ---------------------------- MPD announces state update: update
Mar 14 16:26:55 volumio volumio[1345]: info: sendMpdCommand update took 3 milliseconds
Mar 14 16:26:55 volumio volumio[1345]: info: ControllerMpd::getState
Mar 14 16:26:55 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:55 volumio volumio[1345]: info: sendMpdCommand status took 2 milliseconds
Mar 14 16:26:55 volumio volumio[1345]: info: sendMpdCommand status took 1 milliseconds
Mar 14 16:26:55 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:55 volumio volumio[1345]: info: Command Router : Notfying DB Updatetrue
Mar 14 16:26:55 volumio volumio[1345]: info: CoreCommandRouter::Close All Modals sent
Mar 14 16:26:55 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:55 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 14 16:26:55 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:55 volumio volumio[1345]: info:
Mar 14 16:26:55 volumio volumio[1345]: ---------------------------- MPD announces state update: update
Mar 14 16:26:55 volumio volumio[1345]: info: ControllerMpd::getState
Mar 14 16:26:55 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:55 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:55 volumio volumio[1345]: info:
Mar 14 16:26:55 volumio volumio[1345]: ---------------------------- MPD announces state update: update
Mar 14 16:26:55 volumio volumio[1345]: info: ControllerMpd::getState
Mar 14 16:26:55 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:55 volumio volumio[1345]: info: Initializing connection to go-librespot Websocket
Mar 14 16:26:55 volumio volumio[1345]: info: sendMpdCommand playlistinfo took 4 milliseconds
Mar 14 16:26:55 volumio volumio[1345]: info: sendMpdCommand status took 3 milliseconds
Mar 14 16:26:55 volumio volumio[1345]: info: sendMpdCommand status took 2 milliseconds
Mar 14 16:26:55 volumio volumio[1345]: info: sendMpdCommand status took 2 milliseconds
Mar 14 16:26:55 volumio volumio[1345]: info: sendMpdCommand status took 2 milliseconds
Mar 14 16:26:55 volumio volumio[1345]: verbose: ControllerMpd::parseTrackInfo
Mar 14 16:26:55 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:55 volumio volumio[1345]: info: Command Router : Notfying DB Updatetrue
Mar 14 16:26:55 volumio volumio[1345]: info: CoreCommandRouter::Close All Modals sent
Mar 14 16:26:55 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:55 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 14 16:26:55 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:55 volumio volumio[1345]: info: Command Router : Notfying DB Updatetrue
Mar 14 16:26:55 volumio volumio[1345]: info: CoreCommandRouter::Close All Modals sent
Mar 14 16:26:55 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:55 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 14 16:26:55 volumio volumio[1345]: info: ControllerMpd::pushState
Mar 14 16:26:55 volumio volumio[1345]: info: CoreCommandRouter::servicePushState
Mar 14 16:26:55 volumio volumio[1345]: info: CorePlayQueue::getTrack 6
Mar 14 16:26:55 volumio volumio[1345]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":169928,"duration":174,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"160 Kbps","isStreaming":false,"title":"El solitario","artist":"Los Pakines","album":"Exitos de Oro","uri":"INTERNAL/Los Pakines/Exitos de Oro/07 El solitario.mp3","trackType":"mp3"}
Mar 14 16:26:55 volumio volumio[1345]: verbose: CURRENT POSITION 6
Mar 14 16:26:55 volumio volumio[1345]: info: CoreStateMachine::syncState stateService pause
Mar 14 16:26:55 volumio volumio[1345]: info: CoreStateMachine::syncState currentStatus pause
Mar 14 16:26:55 volumio volumio[1345]: info: CoreStateMachine::pushState
Mar 14 16:26:55 volumio volumio[1345]: info: CorePlayQueue::getTrack 6
Mar 14 16:26:55 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 14 16:26:55 volumio volumio[1345]: info: CoreCommandRouter::volumioPushState
Mar 14 16:26:55 volumio volumio[1345]: info: CoreStateMachine::stPlaybackTimer
Mar 14 16:26:55 volumio volumio[1345]: info: ------------------------------ 196ms
Mar 14 16:26:55 volumio volumio[1345]: SPOTIFY: RECEIVED VOLUMIO VOLUME 6
Mar 14 16:26:55 volumio volumio[1345]: info: sendMpdCommand playlistinfo took 19 milliseconds
Mar 14 16:26:55 volumio volumio[1345]: info: sendMpdCommand playlistinfo took 9 milliseconds
Mar 14 16:26:55 volumio volumio[1345]: verbose: ControllerMpd::parseTrackInfo
Mar 14 16:26:55 volumio volumio[1345]: info: ControllerMpd::pushState
Mar 14 16:26:55 volumio volumio[1345]: info: CoreCommandRouter::servicePushState
Mar 14 16:26:55 volumio volumio[1345]: info: CorePlayQueue::getTrack 6
Mar 14 16:26:55 volumio volumio[1345]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":169928,"duration":174,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"160 Kbps","isStreaming":false,"title":"El solitario","artist":"Los Pakines","album":"Exitos de Oro","uri":"INTERNAL/Los Pakines/Exitos de Oro/07 El solitario.mp3","trackType":"mp3"}
Mar 14 16:26:55 volumio volumio[1345]: verbose: CURRENT POSITION 6
Mar 14 16:26:55 volumio volumio[1345]: info: CoreStateMachine::syncState stateService pause
Mar 14 16:26:55 volumio volumio[1345]: info: CoreStateMachine::syncState currentStatus pause
Mar 14 16:26:55 volumio volumio[1345]: info: CoreStateMachine::pushState
Mar 14 16:26:55 volumio volumio[1345]: info: CorePlayQueue::getTrack 6
Mar 14 16:26:55 volumio volumio[1345]: info: CoreCommandRouter::volumioPushState
Mar 14 16:26:55 volumio volumio[1345]: info: CoreStateMachine::stPlaybackTimer
Mar 14 16:26:55 volumio volumio[1345]: info: ControllerMpd::pushState
Mar 14 16:26:55 volumio volumio[1345]: info: CoreCommandRouter::servicePushState
Mar 14 16:26:55 volumio volumio[1345]: info: CorePlayQueue::getTrack 6
Mar 14 16:26:55 volumio volumio[1345]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":169928,"duration":174,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"160 Kbps","isStreaming":false,"title":"El solitario","artist":"Los Pakines","album":"Exitos de Oro","uri":"INTERNAL/Los Pakines/Exitos de Oro/07 El solitario.mp3","trackType":"mp3"}
Mar 14 16:26:55 volumio volumio[1345]: verbose: CURRENT POSITION 6
Mar 14 16:26:55 volumio volumio[1345]: info: CoreStateMachine::syncState stateService pause
Mar 14 16:26:55 volumio volumio[1345]: info: CoreStateMachine::syncState currentStatus pause
Mar 14 16:26:55 volumio volumio[1345]: info: CoreStateMachine::pushState
Mar 14 16:26:55 volumio volumio[1345]: info: CorePlayQueue::getTrack 6
Mar 14 16:26:55 volumio volumio[1345]: info: CoreCommandRouter::volumioPushState
Mar 14 16:26:55 volumio volumio[1345]: info: CoreStateMachine::stPlaybackTimer
Mar 14 16:26:55 volumio volumio[1345]: info: ------------------------------ 45ms
Mar 14 16:26:55 volumio volumio[1345]: info: ------------------------------ 44ms
Mar 14 16:26:55 volumio volumio[1345]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Mar 14 16:26:55 volumio volumio[1345]: SPOTIFY: RECEIVED VOLUMIO VOLUME 6
Mar 14 16:26:55 volumio volumio[1345]: SPOTIFY: RECEIVED VOLUMIO VOLUME 6
Mar 14 16:26:55 volumio volumio[1345]: info: MPD Database updated - AlbumList cache refreshed
Mar 14 16:26:55 volumio volumio[1345]: info:
Mar 14 16:26:55 volumio volumio[1345]: ---------------------------- MPD announces state update: database
Mar 14 16:26:55 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:55 volumio volumio[1345]: info:
Mar 14 16:26:55 volumio volumio[1345]: ---------------------------- MPD announces state update: update
Mar 14 16:26:55 volumio volumio[1345]: info: ControllerMpd::getState
Mar 14 16:26:55 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:55 volumio volumio[1345]: info: ControllerMpd::getState
Mar 14 16:26:55 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:55 volumio volumio[1345]: info: MPD Database updated - AlbumList cache refreshed
Mar 14 16:26:55 volumio volumio[1345]: info:
Mar 14 16:26:55 volumio volumio[1345]: ---------------------------- MPD announces state update: database
Mar 14 16:26:55 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:55 volumio volumio[1345]: info:
Mar 14 16:26:55 volumio volumio[1345]: ---------------------------- MPD announces state update: update
Mar 14 16:26:55 volumio volumio[1345]: info: ControllerMpd::getState
Mar 14 16:26:55 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:55 volumio volumio[1345]: info: ControllerMpd::getState
Mar 14 16:26:55 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:55 volumio volumio[1345]: info: MPD Database updated - AlbumList cache refreshed
Mar 14 16:26:55 volumio volumio[1345]: info:
Mar 14 16:26:55 volumio volumio[1345]: ---------------------------- MPD announces state update: database
Mar 14 16:26:55 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:55 volumio volumio[1345]: info:
Mar 14 16:26:55 volumio volumio[1345]: ---------------------------- MPD announces state update: update
Mar 14 16:26:55 volumio volumio[1345]: info: ControllerMpd::getState
Mar 14 16:26:55 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:55 volumio volumio[1345]: info: ControllerMpd::getState
Mar 14 16:26:55 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand status
Mar 14 16:26:56 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Mar 14 16:26:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1013.
Mar 14 16:26:56 volumio systemd[1]: Stopped go-librespot Daemon.
Mar 14 16:26:56 volumio systemd[1]: Started go-librespot Daemon.
Mar 14 16:26:56 volumio volumio[1345]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Mar 14 16:26:56 volumio go-librespot[30633]: Librespot-go daemon starting...
Mar 14 16:26:56 volumio go-librespot[30633]: time="2025-03-14T16:26:56+01:00" level=info msg="generated new device id: c113a994bfee8f1e0ad2fdd3b16e524f61d59ce6"
Mar 14 16:26:56 volumio go-librespot[30633]: time="2025-03-14T16:26:56+01:00" level=debug msg="stored credentials not found"
Mar 14 16:26:56 volumio go-librespot[30633]: time="2025-03-14T16:26:56+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Mar 14 16:26:56 volumio go-librespot[30633]: time="2025-03-14T16:26:56+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Mar 14 16:26:56 volumio go-librespot[30633]: time="2025-03-14T16:26:56+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Mar 14 16:26:56 volumio go-librespot[30633]: time="2025-03-14T16:26:56+01:00" level=debug msg="zeroconf server listening on port 38091"
Mar 14 16:26:56 volumio volumio[1345]: info: sendMpdCommand status took 783 milliseconds
Mar 14 16:26:56 volumio volumio[1345]: info: sendMpdCommand status took 783 milliseconds
Mar 14 16:26:56 volumio volumio[1345]: info: sendMpdCommand status took 782 milliseconds
Mar 14 16:26:56 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:56 volumio go-librespot[30633]: time="2025-03-14T16:26:56+01:00" level=debug msg="obtained new client token: AAC1Zlmp9y3tEY92MyZUadfyWe1v7kJJWp6W6qztXJ8prVeTpz3/3DyP+oRS1EnwHCMgdi3n0MMnxHJvVWqs/AY4kUZwEDqAXMdz+iHhOwlEtzIuD39AEmD6D1L71A4rSLQJ/x23/E/0tVThgmHuL/WAWpABz8YhGfyM5s5HbhoJW1w5E84j7CqwisM2lAwuTRdlu+4i29CjeOBFZw4dJANQxRK+LWHiFDoq5iqOcL1qZ2LRucEzWe3LOtNZLg=="
Mar 14 16:26:56 volumio volumio[1345]: info: Command Router : Notfying DB Updatefalse
Mar 14 16:26:56 volumio volumio[1345]: info: CoreCommandRouter::Close All Modals sent
Mar 14 16:26:56 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:56 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 14 16:26:56 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:56 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 14 16:26:56 volumio go-librespot[30633]: time="2025-03-14T16:26:56+01:00" level=info msg="connected to ap-gew4.spotify.com:4070"
Mar 14 16:26:56 volumio go-librespot[30633]: time="2025-03-14T16:26:56+01:00" level=debug msg="completed keyexchange"
Mar 14 16:26:57 volumio volumio[1345]: info: sendMpdCommand status took 1315 milliseconds
Mar 14 16:26:57 volumio volumio[1345]: info: sendMpdCommand status took 1316 milliseconds
Mar 14 16:26:57 volumio volumio[1345]: info: sendMpdCommand status took 1315 milliseconds
Mar 14 16:26:57 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:57 volumio volumio[1345]: info: Command Router : Notfying DB Updatefalse
Mar 14 16:26:57 volumio volumio[1345]: info: CoreCommandRouter::Close All Modals sent
Mar 14 16:26:57 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:57 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 14 16:26:57 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:57 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 14 16:26:57 volumio go-librespot[30633]: time="2025-03-14T16:26:57+01:00" level=debug msg="completed challenge"
Mar 14 16:26:57 volumio go-librespot[30633]: time="2025-03-14T16:26:57+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: failed login: BadCredentials"
Mar 14 16:26:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Mar 14 16:26:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Mar 14 16:26:57 volumio volumio[1345]: info: sendMpdCommand status took 1795 milliseconds
Mar 14 16:26:57 volumio volumio[1345]: info: sendMpdCommand status took 1796 milliseconds
Mar 14 16:26:57 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:57 volumio volumio[1345]: info: Command Router : Notfying DB Updatefalse
Mar 14 16:26:57 volumio volumio[1345]: info: CoreCommandRouter::Close All Modals sent
Mar 14 16:26:57 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:57 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 14 16:26:57 volumio volumio[1345]: verbose: ControllerMpd::parseState
Mar 14 16:26:57 volumio volumio[1345]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 14 16:26:57 volumio volumio[1345]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 14 16:26:57 volumio volumio[1345]: TypeError: Cannot read property 'substring' of undefined
Mar 14 16:26:57 volumio volumio[1345]: at /volumio/app/plugins/music_service/mpd/index.js:2827:70
Mar 14 16:26:57 volumio volumio[1345]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3)
Mar 14 16:26:57 volumio volumio[1345]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12)
Mar 14 16:26:57 volumio volumio[1345]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12)
Mar 14 16:26:57 volumio volumio[1345]: at Socket.emit (events.js:400:28)
Mar 14 16:26:57 volumio volumio[1345]: at addChunk (internal/streams/readable.js:293:12)
Mar 14 16:26:57 volumio volumio[1345]: at readableAddChunk (internal/streams/readable.js:263:11)
Mar 14 16:26:57 volumio volumio[1345]: at Socket.Readable.push (internal/streams/readable.js:206:10)
Mar 14 16:26:57 volumio volumio[1345]: at Pipe.onStreamRead (internal/stream_base_commons.js:188:23)
Mar 14 16:26:57 volumio volumio[1345]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 14 16:26:57 volumio sudo[30671]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-14 16:25
Mar 14 16:26:57 volumio sudo[30671]: pam_unix(sudo:session): session opened for user root by (uid=0)
PRETTY_NAME="Debian GNU/Linux 10 (buster)"
NAME="Debian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
ID=debian
HOME_URL="https://www.debian.org/"
SUPPORT_URL="https://www.debian.org/support"
BUG_REPORT_URL="https://bugs.debian.org/"
VOLUMIO_BUILD_VERSION="70bcab5180cf11352f5a5197ade215ea8ee93db0"
VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6"
VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a"
VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347"
VOLUMIO_ARCH="x64"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 07:25:16 PM CET"
VOLUMIO_VERSION="3.779"
VOLUMIO_HARDWARE="x86_amd64"
VOLUMIO_DEVICENAME="x86_64"
VOLUMIO_HASH="66c567362bdbb3dc1644a18f7879afe7"