-- Logs begin at Mon 2025-01-20 22:31:19 CET, end at Mon 2025-01-20 22:33:21 CET. -- Jan 20 22:32:00 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 20 22:32:00 volumio volumio[817]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jan 20 22:32:00 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jan 20 22:32:00 volumio volumio[817]: info: Received Get System Version Jan 20 22:32:00 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 20 22:32:00 volumio volumio[817]: info: Received Get System Info Jan 20 22:32:00 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 20 22:32:00 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 20 22:32:00 volumio volumio[817]: info: Discovery: Getting this device information Jan 20 22:32:00 volumio volumio[817]: info: CoreCommandRouter::volumioGetState Jan 20 22:32:00 volumio volumio[817]: info: CorePlayQueue::getTrack 0 Jan 20 22:32:00 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 20 22:32:00 volumio volumio[817]: info: CALLMETHOD: audio_interface alsa_controller saveResamplingOpts [object Object] Jan 20 22:32:00 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveResamplingOpts Jan 20 22:32:00 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: mpd , saveResampleOptions Jan 20 22:32:00 volumio sudo[2112]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 20 22:32:00 volumio sudo[2112]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 22:32:00 volumio sudo[2112]: pam_unix(sudo:session): session closed for user root Jan 20 22:32:00 volumio sudo[2115]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 20 22:32:00 volumio sudo[2115]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 22:32:00 volumio volumio[817]: info: MPD Permissions set Jan 20 22:32:00 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 22:32:00 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 22:32:00 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 22:32:00 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 22:32:00 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 22:32:00 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 22:32:00 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 22:32:00 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 22:32:00 volumio systemd[1]: Stopping Music Player Daemon... Jan 20 22:32:00 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 20 22:32:00 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jan 20 22:32:00 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 22:32:00 volumio systemd[1]: mpd.service: Succeeded. Jan 20 22:32:00 volumio systemd[1]: Stopped Music Player Daemon. Jan 20 22:32:00 volumio systemd[1]: Starting Music Player Daemon... Jan 20 22:32:00 volumio sudo[2123]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 20 22:32:00 volumio sudo[2123]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 22:32:00 volumio sudo[2123]: pam_unix(sudo:session): session closed for user root Jan 20 22:32:00 volumio mpd[2125]: Jan 20 22:32 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 20 22:32:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 20 22:32:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 20 22:32:00 volumio systemd[1]: Started Music Player Daemon. Jan 20 22:32:00 volumio sudo[2115]: pam_unix(sudo:session): session closed for user root Jan 20 22:32:00 volumio systemd[1]: Stopped go-librespot Daemon. Jan 20 22:32:00 volumio volumio[817]: error: updateQueue error: null Jan 20 22:32:00 volumio systemd[1]: Started go-librespot Daemon. Jan 20 22:32:00 volumio go-librespot[2128]: Librespot-go daemon starting... Jan 20 22:32:00 volumio go-librespot[2128]: time="2025-01-20T22:32:00+01:00" level=info msg="generated new device id: 15db720410731e7efd5d02f4878ba25883afeb23" Jan 20 22:32:00 volumio go-librespot[2128]: time="2025-01-20T22:32:00+01:00" level=debug msg="stored credentials found for sloam8" Jan 20 22:32:00 volumio go-librespot[2128]: time="2025-01-20T22:32:00+01:00" level=debug msg="obtained new client token: AAAVDft/k0vIWtfLZK1UgaUpGVAH2KkgvMDN483Dx4OWfGK0Fv0ttLPkGynSwzuU+zAmMni61PEDbKBRIyBKtovCOLFdeajEd9EVybsYi+waI74RrMH44DUY6iFn8oG+0EyiFjW/DKikDg4amqB4pc0TpYEdmzrKvhX1R5DkU9g50g/V3UtF1/4NSi7vP7+e2FtGeqTapbsRzvm45EhCTBmrvsJ08LjgD4xWitBoKA0y0soLPxM3PjzVTW+kdQ==" Jan 20 22:32:01 volumio go-librespot[2128]: time="2025-01-20T22:32:01+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 20 22:32:01 volumio go-librespot[2128]: time="2025-01-20T22:32:01+01:00" level=debug msg="completed keyexchange" Jan 20 22:32:01 volumio systemd[1]: systemd-timedated.service: Succeeded. Jan 20 22:32:01 volumio volumio[817]: info: BOOT COMPLETED Jan 20 22:32:01 volumio go-librespot[2128]: time="2025-01-20T22:32:01+01:00" level=debug msg="completed challenge" Jan 20 22:32:01 volumio go-librespot[2128]: time="2025-01-20T22:32:01+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 20 22:32:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 20 22:32:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 20 22:32:02 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Jan 20 22:32:02 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 20 22:32:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 20 22:32:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 20 22:32:04 volumio systemd[1]: Stopped go-librespot Daemon. Jan 20 22:32:04 volumio systemd[1]: Started go-librespot Daemon. Jan 20 22:32:04 volumio go-librespot[2152]: Librespot-go daemon starting... Jan 20 22:32:04 volumio go-librespot[2152]: time="2025-01-20T22:32:04+01:00" level=info msg="generated new device id: 32b53ccbb94566feabbc5955db6e293015dbca3d" Jan 20 22:32:04 volumio go-librespot[2152]: time="2025-01-20T22:32:04+01:00" level=debug msg="stored credentials found for sloam8" Jan 20 22:32:05 volumio go-librespot[2152]: time="2025-01-20T22:32:05+01:00" level=debug msg="obtained new client token: AACOAB0jyb1vLubvLmDaxbNzik5fXHkXgi5hnWfE/tr21I1nscxtpfKmP53SBzwIeOxwztNwcrDza3ozW3NSekUGHCaxbj/XwFInT30OliUD8zZ6T47VhvECaDAynSVUr1IwSQKtOTzb5eORMQ+F46KCSS8TC8qk/4muOiddJs/MlebbFfaMR380yiWJGSLgROkJWQ9bkHw4BzPFzLcvT7VFEY4Ai5AFvTRq1Ks90h+KsBvcUF/bIsXZU+A=" Jan 20 22:32:05 volumio go-librespot[2152]: time="2025-01-20T22:32:05+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 20 22:32:05 volumio go-librespot[2152]: time="2025-01-20T22:32:05+01:00" level=debug msg="completed keyexchange" Jan 20 22:32:05 volumio go-librespot[2152]: time="2025-01-20T22:32:05+01:00" level=debug msg="completed challenge" Jan 20 22:32:05 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Jan 20 22:32:05 volumio go-librespot[2152]: time="2025-01-20T22:32:05+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 20 22:32:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 20 22:32:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 20 22:32:05 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: read ECONNRESET Jan 20 22:32:08 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Jan 20 22:32:08 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 20 22:32:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 20 22:32:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 20 22:32:08 volumio systemd[1]: Stopped go-librespot Daemon. Jan 20 22:32:08 volumio systemd[1]: Started go-librespot Daemon. Jan 20 22:32:08 volumio go-librespot[2163]: Librespot-go daemon starting... Jan 20 22:32:08 volumio go-librespot[2163]: time="2025-01-20T22:32:08+01:00" level=info msg="generated new device id: 8a3f63ec9f4b694ca922197d41415c44c8c2b134" Jan 20 22:32:08 volumio go-librespot[2163]: time="2025-01-20T22:32:08+01:00" level=debug msg="stored credentials found for sloam8" Jan 20 22:32:09 volumio go-librespot[2163]: time="2025-01-20T22:32:09+01:00" level=debug msg="obtained new client token: AAC0mQ/uk5Pjb+VX+ZvpsBooiQMm+RZN4eA3InmTdWrif9nIKbINrDuFb1SEhcylAYg/A/C687BTlv7TqzZAnL3q2G7R6uXp9QEiAiWD34ihdjaP+zPKOUdB82/nPoD8CK9Mv9i1JCCNfd33K58thonXp/FNiwD3tuMPtzGF1FZpy8soMqxAjJS+LeINWxs9WcHxBV6/0Sx7ZInEo3zPpXpTC6V7qS6q0tNr/5LkQkhnsXeR2Qtb5ULjSJE=" Jan 20 22:32:09 volumio go-librespot[2163]: time="2025-01-20T22:32:09+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 20 22:32:09 volumio go-librespot[2163]: time="2025-01-20T22:32:09+01:00" level=debug msg="completed keyexchange" Jan 20 22:32:09 volumio go-librespot[2163]: time="2025-01-20T22:32:09+01:00" level=debug msg="completed challenge" Jan 20 22:32:09 volumio go-librespot[2163]: time="2025-01-20T22:32:09+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 20 22:32:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 20 22:32:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 20 22:32:10 volumio volumio[817]: info: CALLMETHOD: audio_interface alsa_controller saveResamplingOpts [object Object] Jan 20 22:32:10 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveResamplingOpts Jan 20 22:32:10 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: mpd , saveResampleOptions Jan 20 22:32:10 volumio sudo[2172]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 20 22:32:10 volumio sudo[2172]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 22:32:10 volumio sudo[2172]: pam_unix(sudo:session): session closed for user root Jan 20 22:32:10 volumio volumio[817]: info: MPD Permissions set Jan 20 22:32:10 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 22:32:10 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 22:32:10 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 22:32:10 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 22:32:10 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 22:32:10 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 22:32:10 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 22:32:10 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 22:32:10 volumio sudo[2175]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 20 22:32:10 volumio sudo[2175]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 22:32:10 volumio systemd[1]: Stopping Music Player Daemon... Jan 20 22:32:10 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 20 22:32:10 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jan 20 22:32:10 volumio systemd[1]: mpd.service: Succeeded. Jan 20 22:32:10 volumio systemd[1]: Stopped Music Player Daemon. Jan 20 22:32:10 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 22:32:10 volumio systemd[1]: Starting Music Player Daemon... Jan 20 22:32:10 volumio sudo[2182]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 20 22:32:10 volumio sudo[2182]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 22:32:10 volumio sudo[2182]: pam_unix(sudo:session): session closed for user root Jan 20 22:32:10 volumio mpd[2185]: Jan 20 22:32 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 20 22:32:10 volumio systemd[1]: Started Music Player Daemon. Jan 20 22:32:10 volumio sudo[2175]: pam_unix(sudo:session): session closed for user root Jan 20 22:32:10 volumio volumio[817]: error: updateQueue error: null Jan 20 22:32:11 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Jan 20 22:32:11 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 20 22:32:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 20 22:32:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 20 22:32:12 volumio systemd[1]: Stopped go-librespot Daemon. Jan 20 22:32:12 volumio systemd[1]: Started go-librespot Daemon. Jan 20 22:32:12 volumio go-librespot[2188]: Librespot-go daemon starting... Jan 20 22:32:12 volumio go-librespot[2188]: time="2025-01-20T22:32:12+01:00" level=info msg="generated new device id: 9112250bde6b7d23777f2fd51d0ee71c94b64110" Jan 20 22:32:12 volumio go-librespot[2188]: time="2025-01-20T22:32:12+01:00" level=debug msg="stored credentials found for sloam8" Jan 20 22:32:13 volumio go-librespot[2188]: time="2025-01-20T22:32:13+01:00" level=debug msg="obtained new client token: AAAGqEaRKPWir/Q9lkh6o00f5oLjlto7XxPep3urMgeRQy2kY7hq1+tmJZGrUCrDVqXzXylCK6QQvizyIBm/ESgJNJKCxolWHYSl8oLZP/nl+Q2Ax/1V5RO+kSHB/B3FUHmlFu4tovveTzivENFt8GIgaCvKTOub/RrzGykaTFGfa2MLkRsIsyl0HJ0C9bfsFZOT1L2ZO0BwH3zlSYKuqNvsaye5bIZu1BufxSpV+SMxYQrFKZp7XHRzIK4=" Jan 20 22:32:13 volumio go-librespot[2188]: time="2025-01-20T22:32:13+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 20 22:32:13 volumio go-librespot[2188]: time="2025-01-20T22:32:13+01:00" level=debug msg="completed keyexchange" Jan 20 22:32:13 volumio go-librespot[2188]: time="2025-01-20T22:32:13+01:00" level=debug msg="completed challenge" Jan 20 22:32:13 volumio go-librespot[2188]: time="2025-01-20T22:32:13+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 20 22:32:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 20 22:32:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 20 22:32:14 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Jan 20 22:32:14 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 20 22:32:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 20 22:32:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jan 20 22:32:16 volumio systemd[1]: Stopped go-librespot Daemon. Jan 20 22:32:16 volumio systemd[1]: Started go-librespot Daemon. Jan 20 22:32:16 volumio go-librespot[2218]: Librespot-go daemon starting... Jan 20 22:32:16 volumio go-librespot[2218]: time="2025-01-20T22:32:16+01:00" level=info msg="generated new device id: cbaea92937ee7de7b624809908605b8edc620775" Jan 20 22:32:16 volumio go-librespot[2218]: time="2025-01-20T22:32:16+01:00" level=debug msg="stored credentials found for sloam8" Jan 20 22:32:17 volumio go-librespot[2218]: time="2025-01-20T22:32:17+01:00" level=debug msg="obtained new client token: AAAk9Bsh0lAMrQLc5357V/9sCc7iiNox0pKlhEAoA2EdttcZ4pbTBmwOSLZbugBOMuz1yBoYs5uU9fdr0WUugyDTYN5y4J3SrmwwGHKEJy4rBr5p1J8GOAU1mqBZ701SGaKqelLZUZ+jz5kUzh12+95tWN8SRrX6ZtGitKjOPWsxlzawu7Rg6tFFZqr07eB7TMl7lF1ZHtRWfqy8Hzb1cM9UNZ9+nVTsxg0SUZ8Ir9OKZQFg1Dquez3Vxzk=" Jan 20 22:32:17 volumio go-librespot[2218]: time="2025-01-20T22:32:17+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 20 22:32:17 volumio go-librespot[2218]: time="2025-01-20T22:32:17+01:00" level=debug msg="completed keyexchange" Jan 20 22:32:17 volumio go-librespot[2218]: time="2025-01-20T22:32:17+01:00" level=debug msg="completed challenge" Jan 20 22:32:17 volumio go-librespot[2218]: time="2025-01-20T22:32:17+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 20 22:32:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 20 22:32:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 20 22:32:17 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Jan 20 22:32:17 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 20 22:32:20 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Jan 20 22:32:20 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 20 22:32:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 20 22:32:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Jan 20 22:32:20 volumio systemd[1]: Stopped go-librespot Daemon. Jan 20 22:32:20 volumio systemd[1]: Started go-librespot Daemon. Jan 20 22:32:20 volumio go-librespot[2226]: Librespot-go daemon starting... Jan 20 22:32:20 volumio go-librespot[2226]: time="2025-01-20T22:32:20+01:00" level=info msg="generated new device id: df7bc73863f5c97249019255386e336f7b6577f4" Jan 20 22:32:20 volumio go-librespot[2226]: time="2025-01-20T22:32:20+01:00" level=debug msg="stored credentials found for sloam8" Jan 20 22:32:21 volumio go-librespot[2226]: time="2025-01-20T22:32:21+01:00" level=debug msg="obtained new client token: AABf82kQ4KbsLhEaxJN5ojsx2Yd7cEBwLy2b6NpvXRTw7zxQHE3DOxavg00sKrFV24thSHx/PMrkOsDMBP3+fjB9G9OJ4o1tZ6eWchfOMhwkkpHNrv/9n5bTpkXE/CuGZ1o2lX6ee9zvkPo83Jaz7SCfNpSnuMcZhrl4AvRS/OMd68L2axWtaK0nmrPUDS1HTtDg8MXEssCaJr9hOaAf6IHQD6L7Q2kkkd+Xd8D0NvnYmczwqwzneNg0byY=" Jan 20 22:32:21 volumio go-librespot[2226]: time="2025-01-20T22:32:21+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 20 22:32:21 volumio go-librespot[2226]: time="2025-01-20T22:32:21+01:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.65.9:4070: connect: connection refused" Jan 20 22:32:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 20 22:32:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 20 22:32:22 volumio volumio[817]: info: CoreCommandRouter::volumioGetState Jan 20 22:32:22 volumio volumio[817]: info: CorePlayQueue::getTrack 0 Jan 20 22:32:23 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Jan 20 22:32:23 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 20 22:32:24 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 20 22:32:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Jan 20 22:32:24 volumio systemd[1]: Stopped go-librespot Daemon. Jan 20 22:32:24 volumio systemd[1]: Started go-librespot Daemon. Jan 20 22:32:24 volumio go-librespot[2292]: Librespot-go daemon starting... Jan 20 22:32:24 volumio go-librespot[2292]: time="2025-01-20T22:32:24+01:00" level=info msg="generated new device id: 622d7d13815cb205a5518b9667461c921893b483" Jan 20 22:32:24 volumio go-librespot[2292]: time="2025-01-20T22:32:24+01:00" level=debug msg="stored credentials found for sloam8" Jan 20 22:32:24 volumio go-librespot[2292]: time="2025-01-20T22:32:24+01:00" level=debug msg="obtained new client token: AAD87krsLplBpC2SQZMWYPAMq+Qcmgaxc5atrUOxSB2QcMsiGFYL8VpVNqVk18houaosvelAI6EhH6Zj9I0aoqyEl5smbnBsO98Lm5YUpA5R5MO19H0IFUoebZGtibtHI/JvNBf8vGlYfZtxiaEbrJop0pm0iSYK3ftxtt6sg+qyfyfz8DyMsB66YvRkZCUEVnghwV8irvwCLXZob93r+fMFrb96Btp8QQYre924miqFiTVaz01wZsOz3GeNYA==" Jan 20 22:32:24 volumio go-librespot[2292]: time="2025-01-20T22:32:24+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 20 22:32:24 volumio go-librespot[2292]: time="2025-01-20T22:32:24+01:00" level=debug msg="completed keyexchange" Jan 20 22:32:25 volumio go-librespot[2292]: time="2025-01-20T22:32:25+01:00" level=debug msg="completed challenge" Jan 20 22:32:25 volumio go-librespot[2292]: time="2025-01-20T22:32:25+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 20 22:32:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 20 22:32:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 20 22:32:26 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Jan 20 22:32:26 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 20 22:32:28 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 20 22:32:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 20 22:32:28 volumio systemd[1]: Stopped go-librespot Daemon. Jan 20 22:32:28 volumio systemd[1]: Started go-librespot Daemon. Jan 20 22:32:28 volumio go-librespot[2309]: Librespot-go daemon starting... Jan 20 22:32:28 volumio go-librespot[2309]: time="2025-01-20T22:32:28+01:00" level=info msg="generated new device id: d02a137b7091fb23ca21f22c12251950d910d253" Jan 20 22:32:28 volumio go-librespot[2309]: time="2025-01-20T22:32:28+01:00" level=debug msg="stored credentials found for sloam8" Jan 20 22:32:28 volumio go-librespot[2309]: time="2025-01-20T22:32:28+01:00" level=debug msg="obtained new client token: AABZ0w2qdL0uUaWYXAowVwu7uhOXUnKuVBv3sBCL/QDLNV9sdevAOFeHKtAGYUan/RnJ9374dVvllVXpXsH44JkluHvyfhvpRaO+yR4g0aryHhWBSjsVPGwPmB5MLgxpaaPlXiELfT1NGMD8lZRBx0Plug4Fh30lrFsyHB7tZB2X6JVun5c7wsC0yaC4UarE2ffjW2BOtx2PgYgUAcfwSSJjU7qzU39laTHg0ZvgQl02NhVLenoMm5WLGofGCA==" Jan 20 22:32:28 volumio go-librespot[2309]: time="2025-01-20T22:32:28+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 20 22:32:28 volumio go-librespot[2309]: time="2025-01-20T22:32:28+01:00" level=debug msg="completed keyexchange" Jan 20 22:32:29 volumio go-librespot[2309]: time="2025-01-20T22:32:29+01:00" level=debug msg="completed challenge" Jan 20 22:32:29 volumio go-librespot[2309]: time="2025-01-20T22:32:29+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 20 22:32:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 20 22:32:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 20 22:32:29 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Jan 20 22:32:29 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 20 22:32:32 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 20 22:32:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 20 22:32:32 volumio systemd[1]: Stopped go-librespot Daemon. Jan 20 22:32:32 volumio systemd[1]: Started go-librespot Daemon. Jan 20 22:32:32 volumio go-librespot[2318]: Librespot-go daemon starting... Jan 20 22:32:32 volumio go-librespot[2318]: time="2025-01-20T22:32:32+01:00" level=info msg="generated new device id: 9a7a06257c019b01fe6c8c3ea61591771b67acf9" Jan 20 22:32:32 volumio go-librespot[2318]: time="2025-01-20T22:32:32+01:00" level=debug msg="stored credentials found for sloam8" Jan 20 22:32:32 volumio go-librespot[2318]: time="2025-01-20T22:32:32+01:00" level=debug msg="obtained new client token: AAAsFDti7nvXDJyCwCQYwltg38kMeugRclJgs8pk1k1LQvUayUUN8PGcLPdPPj7mPwZswL7IKJOFzioext6hpN4N/SCVBlk6H5SGYLHgKJqbZGoRnR97QykRyJATwIsAsRynHfLxswa9LNXbVeqQk41Hi+OOtMSUAZSTWl9TQVDhZpAWgIcDTjcPBtBIBn9pXFOOSv+lSSMCkHWA67EEPznekFRIXEo2yqeKD2vthrY1tInpzQeZploV8CFuew==" Jan 20 22:32:32 volumio go-librespot[2318]: time="2025-01-20T22:32:32+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 20 22:32:32 volumio go-librespot[2318]: time="2025-01-20T22:32:32+01:00" level=debug msg="completed keyexchange" Jan 20 22:32:32 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Jan 20 22:32:32 volumio go-librespot[2318]: time="2025-01-20T22:32:32+01:00" level=debug msg="new websocket client" Jan 20 22:32:32 volumio volumio[817]: info: Connection to go-librespot Websocket established Jan 20 22:32:33 volumio go-librespot[2318]: time="2025-01-20T22:32:33+01:00" level=debug msg="completed challenge" Jan 20 22:32:33 volumio go-librespot[2318]: time="2025-01-20T22:32:33+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 20 22:32:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 20 22:32:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 20 22:32:33 volumio volumio[817]: info: Connection to go-librespot Websocket closed Jan 20 22:32:35 volumio volumio[817]: info: Getting Spotify volume Jan 20 22:32:35 volumio volumio[817]: (node:817) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 20 22:32:35 volumio volumio[817]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) Jan 20 22:32:35 volumio volumio[817]: (node:817) 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: 4) Jan 20 22:32:35 volumio volumio[817]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jan 20 22:32:35 volumio volumio[817]: info: CoreCommandRouter::volumioGetState Jan 20 22:32:35 volumio volumio[817]: info: CorePlayQueue::getTrack 0 Jan 20 22:32:35 volumio volumio[817]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Jan 20 22:32:36 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Jan 20 22:32:36 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 20 22:32:36 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 20 22:32:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jan 20 22:32:36 volumio systemd[1]: Stopped go-librespot Daemon. Jan 20 22:32:36 volumio kernel: usb 3-1: USB disconnect, device number 2 Jan 20 22:32:36 volumio volumio[817]: info: No valid Plugin REST Endpoint Jan 20 22:32:36 volumio volumio[817]: info: Jan 20 22:32:36 volumio volumio[817]: ---------------------------- USB Audio Device Detached Jan 20 22:32:36 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioDetach Jan 20 22:32:36 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 20 22:32:36 volumio systemd[1]: Started go-librespot Daemon. Jan 20 22:32:36 volumio thd[662]: Error reading device '/dev/input/event3' Jan 20 22:32:36 volumio go-librespot[2347]: Librespot-go daemon starting... Jan 20 22:32:36 volumio volumio[817]: aplay: device_list:272: no soundcards found... Jan 20 22:32:36 volumio go-librespot[2347]: time="2025-01-20T22:32:36+01:00" level=info msg="generated new device id: 25e413add58b41e7d618b8866aa49548655e2c7f" Jan 20 22:32:36 volumio go-librespot[2347]: time="2025-01-20T22:32:36+01:00" level=debug msg="stored credentials found for sloam8" Jan 20 22:32:36 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: raat , onStop Jan 20 22:32:36 volumio systemd[1]: Stopped target Sound Card. Jan 20 22:32:36 volumio go-librespot[2347]: time="2025-01-20T22:32:36+01:00" level=debug msg="obtained new client token: AADNoSruz/h+uBgIa9g3wuGU7HbBE8C6Zo5AlNZGPE9RpDYHxARHQ69M/cGNvwCirjHf5eHsoP98q55qj1HkSQ57fKj2OLRZoeTyC7mpON3t5jeXQ0fMvGiEv6aVX2mKyKkH8XgMBuyUS+Rmxe0EefMgugtBqzhxIcKYMpQuT0hBElaWgeOFht6M9mt82KuAsQwQW9Yj1PcqUzelzYMGeHG9P6MjNE88izxF87ZL+MqmC+rOSs0CZNA1ebM9Pg==" Jan 20 22:32:36 volumio go-librespot[2347]: time="2025-01-20T22:32:36+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 20 22:32:36 volumio go-librespot[2347]: time="2025-01-20T22:32:36+01:00" level=debug msg="completed keyexchange" Jan 20 22:32:37 volumio go-librespot[2347]: time="2025-01-20T22:32:37+01:00" level=debug msg="completed challenge" Jan 20 22:32:37 volumio go-librespot[2347]: time="2025-01-20T22:32:37+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 20 22:32:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 20 22:32:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 20 22:32:39 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Jan 20 22:32:39 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 20 22:32:40 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 20 22:32:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Jan 20 22:32:40 volumio systemd[1]: Stopped go-librespot Daemon. Jan 20 22:32:40 volumio systemd[1]: Started go-librespot Daemon. Jan 20 22:32:40 volumio go-librespot[2363]: Librespot-go daemon starting... Jan 20 22:32:40 volumio go-librespot[2363]: time="2025-01-20T22:32:40+01:00" level=info msg="generated new device id: 08ed9b18060cded431c330613e5c05d07ab3c464" Jan 20 22:32:40 volumio go-librespot[2363]: time="2025-01-20T22:32:40+01:00" level=debug msg="stored credentials found for sloam8" Jan 20 22:32:40 volumio go-librespot[2363]: time="2025-01-20T22:32:40+01:00" level=debug msg="obtained new client token: AACfjIP5wwu+9/XzO3+f0okdv27pTquvlHZ5V1PqJcpk5iq1f57Eyi3fjWcAwcycv+MbEy5a8EBXFVRoPV9U01/9uJwFadND06zaeems5DQFIXb+TO+kSMCquMlrv6OotmYgzRRF1wTvir28xQVGh5Gro1HYu4j02Eor/7KE3/F6ORm4Vrxt9ExgEEesF0Bsm78N0Ipo48DincIHh08uFicYJh0XD9M77Vg36+GWWhVlKQ4K+sXu9mgW1oBzTA==" Jan 20 22:32:40 volumio go-librespot[2363]: time="2025-01-20T22:32:40+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 20 22:32:40 volumio go-librespot[2363]: time="2025-01-20T22:32:40+01:00" level=debug msg="completed keyexchange" Jan 20 22:32:41 volumio go-librespot[2363]: time="2025-01-20T22:32:41+01:00" level=debug msg="completed challenge" Jan 20 22:32:41 volumio go-librespot[2363]: time="2025-01-20T22:32:41+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 20 22:32:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 20 22:32:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 20 22:32:42 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Jan 20 22:32:42 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 20 22:32:43 volumio kernel: usb 3-1: new full-speed USB device number 3 using xhci_hcd Jan 20 22:32:43 volumio kernel: usb 3-1: device descriptor read/64, error -71 Jan 20 22:32:44 volumio kernel: usb 3-1: device descriptor read/64, error -71 Jan 20 22:32:44 volumio kernel: usb 3-1: new full-speed USB device number 4 using xhci_hcd Jan 20 22:32:44 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 20 22:32:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Jan 20 22:32:44 volumio systemd[1]: Stopped go-librespot Daemon. Jan 20 22:32:44 volumio systemd[1]: Started go-librespot Daemon. Jan 20 22:32:44 volumio go-librespot[2386]: Librespot-go daemon starting... Jan 20 22:32:44 volumio go-librespot[2386]: time="2025-01-20T22:32:44+01:00" level=info msg="generated new device id: 8f61856506efdf2719e5be4ad0fc3a142766d77f" Jan 20 22:32:44 volumio go-librespot[2386]: time="2025-01-20T22:32:44+01:00" level=debug msg="stored credentials found for sloam8" Jan 20 22:32:44 volumio kernel: usb 3-1: device descriptor read/64, error -71 Jan 20 22:32:44 volumio go-librespot[2386]: time="2025-01-20T22:32:44+01:00" level=debug msg="obtained new client token: AAC5Gv49CTjYpeFMwTbg7JWeUTWx1AC6eG300mxeRUS0xuNPDe9/UDJ4InF9GZRS159PLdjBdNq3QFPK8NAP2RraR962RPG1RLj6LUONW0JN79NWOCa73cAwN826V7ZtL2y3LC4yE73xOuowjTU94YZHrV3HeGw1odn2GSlUoG2VWbnBAsElqsfw/DvAQglaAbP/L5A4ADn5Hdy9OjxTe4zdhMM3pftZkW3fnwpLJqOvy+rOK9OYozCkAv7loA==" Jan 20 22:32:44 volumio go-librespot[2386]: time="2025-01-20T22:32:44+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 20 22:32:44 volumio kernel: usb 3-1: device descriptor read/64, error -71 Jan 20 22:32:44 volumio go-librespot[2386]: time="2025-01-20T22:32:44+01:00" level=debug msg="completed keyexchange" Jan 20 22:32:44 volumio kernel: usb usb3-port1: attempt power cycle Jan 20 22:32:45 volumio go-librespot[2386]: time="2025-01-20T22:32:45+01:00" level=debug msg="completed challenge" Jan 20 22:32:45 volumio go-librespot[2386]: time="2025-01-20T22:32:45+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 20 22:32:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 20 22:32:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 20 22:32:45 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Jan 20 22:32:45 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 20 22:32:45 volumio kernel: usb 3-1: new high-speed USB device number 5 using xhci_hcd Jan 20 22:32:45 volumio kernel: usb 3-1: New USB device found, idVendor=28d4, idProduct=0008, bcdDevice= 6.f2 Jan 20 22:32:45 volumio kernel: usb 3-1: New USB device strings: Mfr=1, Product=3, SerialNumber=0 Jan 20 22:32:45 volumio kernel: usb 3-1: Product: Expert Pro USB Audio 2.0 Jan 20 22:32:45 volumio kernel: usb 3-1: Manufacturer: DEVIALET Jan 20 22:32:46 volumio kernel: input: DEVIALET Expert Pro USB Audio 2.0 as /devices/pci0000:00/0000:00:1c.0/0000:02:00.0/usb3/3-1/3-1:1.4/0003:28D4:0008.0003/input/input6 Jan 20 22:32:47 volumio kernel: hid-generic 0003:28D4:0008.0003: input,hidraw0: USB HID v1.10 Device [DEVIALET Expert Pro USB Audio 2.0] on usb-0000:02:00.0-1/input4 Jan 20 22:32:47 volumio systemd[1]: Reached target Sound Card. Jan 20 22:32:47 volumio volumio[817]: info: Jan 20 22:32:47 volumio volumio[817]: ---------------------------- USB Audio Device Attached Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioAttach Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::Close All Modals sent Jan 20 22:32:47 volumio volumio[817]: info: Preparing to save Alsa Options, stopping services first Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::volumioGetState Jan 20 22:32:47 volumio volumio[817]: info: CorePlayQueue::getTrack 0 Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::volumioPause Jan 20 22:32:47 volumio volumio[817]: info: CoreStateMachine::pause Jan 20 22:32:47 volumio volumio[817]: info: Saving Audio Output to: {"disallowPush":true,"output_device":{"value":"5","label":"Expert Pro USB Audio 2.0","alsacard":"E20"},"i2s":false} Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 20 22:32:47 volumio volumio[817]: info: Setting mixer Expert Pro USB Audio 2.0 for card Expert Pro USB Audio 2.0 Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::volumioUpdateVolumeSettings Jan 20 22:32:47 volumio volumio[817]: info: Updating Volume Controller Parameters: Device: 5 Name: Expert Pro USB Audio 2.0 Mixer: Expert Pro USB Audio 2.0 Max Vol: 80 Vol Curve; logarithmic Vol Steps: 1 Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Jan 20 22:32:47 volumio volumio[817]: info: Disabling external Volume Control Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 20 22:32:47 volumio volumio[817]: info: Preparing to generate the ALSA configuration file Jan 20 22:32:47 volumio volumio[817]: info: No valid Plugin REST Endpoint Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jan 20 22:32:47 volumio volumio[817]: info: Asound.conf file unchanged, so no further update is needed Jan 20 22:32:47 volumio volumio[817]: info: Output device has changed, restarting MPD Jan 20 22:32:47 volumio sudo[2427]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 20 22:32:47 volumio sudo[2427]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 22:32:47 volumio systemd-udevd[2399]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Jan 20 22:32:47 volumio volumio[817]: info: Output device has changed, restarting Shairport Sync Jan 20 22:32:47 volumio sudo[2427]: pam_unix(sudo:session): session closed for user root Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 20 22:32:47 volumio sudo[2431]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 20 22:32:47 volumio sudo[2431]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 22:32:47 volumio systemd[1]: Stopping Music Player Daemon... Jan 20 22:32:47 volumio systemd[1]: mpd.service: Succeeded. Jan 20 22:32:47 volumio systemd[1]: Stopped Music Player Daemon. Jan 20 22:32:47 volumio volumio[817]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 20 22:32:47 volumio volumio[817]: info: VolumeController:: Volume=73 Mute =false Jan 20 22:32:47 volumio volumio[817]: info: CoreStateMachine::pushState Jan 20 22:32:47 volumio volumio[817]: info: CorePlayQueue::getTrack 0 Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::volumioPushState Jan 20 22:32:47 volumio volumio[817]: SPOTIFY: RECEIVED VOLUMIO VOLUME 73 Jan 20 22:32:47 volumio volumio[817]: SPOTIFY: SPOTIFY VOLUME 75 Jan 20 22:32:47 volumio volumio[817]: SPOTIFY: VOLUMIO VOLUME 73 Jan 20 22:32:47 volumio volumio[817]: SPOTIFY: DELTA VOLUME ENOUGH: true Jan 20 22:32:47 volumio volumio[817]: info: Setting Spotify Volume from Volumio: 73 Jan 20 22:32:47 volumio volumio[817]: info: MPD Permissions set Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 22:32:47 volumio volumio[817]: info: Starting Shairport Sync Jan 20 22:32:47 volumio systemd[1]: Starting Music Player Daemon... Jan 20 22:32:47 volumio sudo[2444]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 20 22:32:47 volumio sudo[2444]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 22:32:47 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 20 22:32:47 volumio systemd[1]: shairport-sync.service: Succeeded. Jan 20 22:32:47 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 20 22:32:47 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 20 22:32:47 volumio sudo[2444]: pam_unix(sudo:session): session closed for user root Jan 20 22:32:47 volumio volumio[817]: info: Shairport-Sync Started Jan 20 22:32:47 volumio sudo[2436]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 20 22:32:47 volumio sudo[2436]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 22:32:47 volumio sudo[2436]: pam_unix(sudo:session): session closed for user root Jan 20 22:32:47 volumio mpd[2449]: Jan 20 22:32 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 20 22:32:47 volumio systemd[1]: Started Music Player Daemon. Jan 20 22:32:47 volumio sudo[2431]: pam_unix(sudo:session): session closed for user root Jan 20 22:32:47 volumio volumio[817]: error: updateQueue error: null Jan 20 22:32:47 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: raat , restartRaat Jan 20 22:32:48 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Jan 20 22:32:48 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 20 22:32:48 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 20 22:32:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Jan 20 22:32:48 volumio systemd[1]: Stopped go-librespot Daemon. Jan 20 22:32:48 volumio systemd[1]: Started go-librespot Daemon. Jan 20 22:32:48 volumio go-librespot[2453]: Librespot-go daemon starting... Jan 20 22:32:48 volumio go-librespot[2453]: time="2025-01-20T22:32:48+01:00" level=info msg="generated new device id: c12b5afc807609e615fd87ea14770b40283beeae" Jan 20 22:32:48 volumio go-librespot[2453]: time="2025-01-20T22:32:48+01:00" level=debug msg="stored credentials found for sloam8" Jan 20 22:32:48 volumio go-librespot[2453]: time="2025-01-20T22:32:48+01:00" level=debug msg="obtained new client token: AAAhGIOiDfT3TaBMUB9e5D1RDztC5uOqSQMN9Zd6WySrT3xwuRafI1bT/QJwFpcIHGUMc6OodCxxyae4uX/xInDlE/ED13cK3qqTAulQH1Am2FsG2BWI0sUpZbcgPmi7A1Y66JniAUHfwFVG09HCuZLQDjl2Yv09Wsebe6qKBtv6vvkKDyWRzG9vJ63bDYD+SoOLZHcV4xZm+Ivl5LhQPxdcDkrcS0OAn7/Oxbi4nyCin5byZ08Znk1OEQ74Kg==" Jan 20 22:32:48 volumio go-librespot[2453]: time="2025-01-20T22:32:48+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 20 22:32:48 volumio volumio[817]: SPOTIFY: SETTING SPOTIFY VOLUME 73 Jan 20 22:32:48 volumio volumio[817]: info: Sending Spotify command with payload to local API: /player/volume Jan 20 22:32:48 volumio go-librespot[2453]: time="2025-01-20T22:32:48+01:00" level=debug msg="completed keyexchange" Jan 20 22:32:49 volumio go-librespot[2453]: time="2025-01-20T22:32:49+01:00" level=debug msg="completed challenge" Jan 20 22:32:49 volumio go-librespot[2453]: time="2025-01-20T22:32:49+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 20 22:32:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 20 22:32:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 20 22:32:49 volumio volumio[817]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Jan 20 22:32:51 volumio volumio[817]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Jan 20 22:32:51 volumio volumio[817]: info: CoreStateMachine::getcurrentVolume Jan 20 22:32:51 volumio volumio[817]: info: CoreCommandRouter::volumioRetrievevolume Jan 20 22:32:51 volumio volumio[817]: info: VolumeController:: Volume=73 Mute =false Jan 20 22:32:51 volumio volumio[817]: info: CoreStateMachine::pushState Jan 20 22:32:51 volumio volumio[817]: info: CorePlayQueue::getTrack 0 Jan 20 22:32:51 volumio volumio[817]: info: CoreCommandRouter::volumioPushState Jan 20 22:32:51 volumio volumio[817]: info: CoreStateMachine::updateTrackBlock Jan 20 22:32:51 volumio volumio[817]: info: CorePlayQueue::getTrackBlock Jan 20 22:32:51 volumio volumio[817]: info: CoreCommandRouter::volumioRetrievevolume Jan 20 22:32:51 volumio volumio[817]: SPOTIFY: RECEIVED VOLUMIO VOLUME 73 Jan 20 22:32:51 volumio volumio[817]: info: VolumeController:: Volume=73 Mute =false Jan 20 22:32:51 volumio volumio[817]: info: CoreStateMachine::pushState Jan 20 22:32:51 volumio volumio[817]: info: CorePlayQueue::getTrack 0 Jan 20 22:32:51 volumio volumio[817]: info: CoreCommandRouter::volumioPushState Jan 20 22:32:51 volumio volumio[817]: SPOTIFY: RECEIVED VOLUMIO VOLUME 73 Jan 20 22:32:51 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Jan 20 22:32:51 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 20 22:32:52 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 20 22:32:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Jan 20 22:32:52 volumio systemd[1]: Stopped go-librespot Daemon. Jan 20 22:32:52 volumio systemd[1]: Started go-librespot Daemon. Jan 20 22:32:52 volumio go-librespot[2465]: Librespot-go daemon starting... Jan 20 22:32:52 volumio go-librespot[2465]: time="2025-01-20T22:32:52+01:00" level=info msg="generated new device id: d3ded49edb3b070a73d54f39d15f071d477b01c9" Jan 20 22:32:52 volumio go-librespot[2465]: time="2025-01-20T22:32:52+01:00" level=debug msg="stored credentials found for sloam8" Jan 20 22:32:52 volumio go-librespot[2465]: time="2025-01-20T22:32:52+01:00" level=debug msg="obtained new client token: AACAqAJP9QmXyqGxwOczXQPySkdzz1A3lmgUS9p64LRiSyk7XjhI9uqkgKJ/fXd0RrAHvvzl0HP9Z+2sr2ReabjrpA1TgQMn2gxC6vcj0q0mnkNnlWuHmCG3gxs6ZysHdDGRqADy1Dg6fzM6oCNRA0YTM3ZzdXU6s3NEjCplOwdgKnaUQiDf4OQnl3rPyL61g4AroTNVxvbtImBSMrKTKZsWOZfbu5mrgxIrOwIcTHorAPlaMA9xPehbZmMPjQ==" Jan 20 22:32:52 volumio go-librespot[2465]: time="2025-01-20T22:32:52+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 20 22:32:52 volumio go-librespot[2465]: time="2025-01-20T22:32:52+01:00" level=debug msg="completed keyexchange" Jan 20 22:32:53 volumio go-librespot[2465]: time="2025-01-20T22:32:53+01:00" level=debug msg="completed challenge" Jan 20 22:32:53 volumio go-librespot[2465]: time="2025-01-20T22:32:53+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 20 22:32:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 20 22:32:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 20 22:32:54 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Jan 20 22:32:54 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 20 22:32:56 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 20 22:32:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Jan 20 22:32:56 volumio systemd[1]: Stopped go-librespot Daemon. Jan 20 22:32:56 volumio systemd[1]: Started go-librespot Daemon. Jan 20 22:32:56 volumio go-librespot[2490]: Librespot-go daemon starting... Jan 20 22:32:56 volumio go-librespot[2490]: time="2025-01-20T22:32:56+01:00" level=info msg="generated new device id: 229ef99ee956f04f5826dbd08ea1fed7de863acc" Jan 20 22:32:56 volumio go-librespot[2490]: time="2025-01-20T22:32:56+01:00" level=debug msg="stored credentials found for sloam8" Jan 20 22:32:56 volumio go-librespot[2490]: time="2025-01-20T22:32:56+01:00" level=debug msg="obtained new client token: AADrVp+bWq6jRs7Z2aYtdi4ReeyoyoSf8Ol1mkUM5slIBW3C9dY5EM7lMrO4cfHoB+mJsyg3iB2Ek+bEP3uPovisWqFr+Lwi9/NKULAsmN20HJlzP7lenMSmoGbkjP98w38nJOjy9a8ydfIjPbxwd3bT6YqUJpWgRvdm3Q3Hp7wcXadmzJyksgxTA4dUG8/j/HLeCnoGV+2iIRH7SwAHzz1yj+B2SLClkWHJPz/bAdd+SHx/AqlBh4e0m0vYBw==" Jan 20 22:32:56 volumio go-librespot[2490]: time="2025-01-20T22:32:56+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 20 22:32:56 volumio go-librespot[2490]: time="2025-01-20T22:32:56+01:00" level=debug msg="completed keyexchange" Jan 20 22:32:57 volumio go-librespot[2490]: time="2025-01-20T22:32:57+01:00" level=debug msg="completed challenge" Jan 20 22:32:57 volumio go-librespot[2490]: time="2025-01-20T22:32:57+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 20 22:32:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 20 22:32:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 20 22:32:57 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Jan 20 22:32:57 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 20 22:33:00 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Jan 20 22:33:00 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 20 22:33:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 20 22:33:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Jan 20 22:33:00 volumio systemd[1]: Stopped go-librespot Daemon. Jan 20 22:33:00 volumio systemd[1]: Started go-librespot Daemon. Jan 20 22:33:00 volumio go-librespot[2498]: Librespot-go daemon starting... Jan 20 22:33:00 volumio go-librespot[2498]: time="2025-01-20T22:33:00+01:00" level=info msg="generated new device id: 0a95ddfc86387066512b537daff0e6fe2a91e2aa" Jan 20 22:33:00 volumio go-librespot[2498]: time="2025-01-20T22:33:00+01:00" level=debug msg="stored credentials found for sloam8" Jan 20 22:33:00 volumio go-librespot[2498]: time="2025-01-20T22:33:00+01:00" level=debug msg="obtained new client token: AADu9JZJmTQRsbtDFQMdpR8jjFIEYOfMJ8tw1qaTgZGhM4wY+MYJxTqLaFlzRISdWSaq3KVqeu+QbFEcB5ho557Xol9QuyC82GOJyc6Ghfc7g5w2wB94bA9yOXNQ7GQMypmYN24gnLkAyNcRLuj/NvhyiobBMw7VgaXYvz6SYlQTcI7leMZrRYhftUPBP7FMrHeCazo5OvyAP3h8gFhd90vvSYReB/BneBX2QFhE3fKjrNtObiLAfbvJU8pvHg==" Jan 20 22:33:00 volumio go-librespot[2498]: time="2025-01-20T22:33:00+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 20 22:33:00 volumio go-librespot[2498]: time="2025-01-20T22:33:00+01:00" level=debug msg="completed keyexchange" Jan 20 22:33:01 volumio go-librespot[2498]: time="2025-01-20T22:33:01+01:00" level=debug msg="completed challenge" Jan 20 22:33:01 volumio go-librespot[2498]: time="2025-01-20T22:33:01+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 20 22:33:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 20 22:33:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 20 22:33:03 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Jan 20 22:33:03 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 20 22:33:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 20 22:33:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Jan 20 22:33:04 volumio systemd[1]: Stopped go-librespot Daemon. Jan 20 22:33:04 volumio systemd[1]: Started go-librespot Daemon. Jan 20 22:33:04 volumio go-librespot[2521]: Librespot-go daemon starting... Jan 20 22:33:04 volumio go-librespot[2521]: time="2025-01-20T22:33:04+01:00" level=info msg="generated new device id: 73dc2c52f6465422c544b57b01e035f27252383f" Jan 20 22:33:04 volumio go-librespot[2521]: time="2025-01-20T22:33:04+01:00" level=debug msg="stored credentials found for sloam8" Jan 20 22:33:04 volumio go-librespot[2521]: time="2025-01-20T22:33:04+01:00" level=debug msg="obtained new client token: AAAlbbTSPzwIxSMhOt+pAwj+ibWVA0ajMKsuDdydqLvI7jrn7YnvJdXJGori8ke9HBScMRIEfvT8N82idKohrg25XICDPBZ4VLSYXBMYlzUfxxft4z3CYH3aV22tgPo0tTTxwqZgQAOf76r+2gFn1qsZn0zqyuM/Ma+xMK/6z61j3KQRuGiyFRZek/ehIn6Q0jzf+1/LrC6NJzl7WNYYUnaMU1UMvXBB7EIyhVp6CiyB9l2V+z1hZW5N1+diDA==" Jan 20 22:33:04 volumio go-librespot[2521]: time="2025-01-20T22:33:04+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 20 22:33:04 volumio go-librespot[2521]: time="2025-01-20T22:33:04+01:00" level=debug msg="completed keyexchange" Jan 20 22:33:05 volumio go-librespot[2521]: time="2025-01-20T22:33:05+01:00" level=debug msg="completed challenge" Jan 20 22:33:05 volumio go-librespot[2521]: time="2025-01-20T22:33:05+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 20 22:33:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 20 22:33:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 20 22:33:06 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Jan 20 22:33:06 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 20 22:33:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 20 22:33:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Jan 20 22:33:08 volumio systemd[1]: Stopped go-librespot Daemon. Jan 20 22:33:08 volumio systemd[1]: Started go-librespot Daemon. Jan 20 22:33:08 volumio go-librespot[2533]: Librespot-go daemon starting... Jan 20 22:33:08 volumio go-librespot[2533]: time="2025-01-20T22:33:08+01:00" level=info msg="generated new device id: 532de83ba01c2b64f951841d6b5c1475a08f8833" Jan 20 22:33:08 volumio go-librespot[2533]: time="2025-01-20T22:33:08+01:00" level=debug msg="stored credentials found for sloam8" Jan 20 22:33:08 volumio go-librespot[2533]: time="2025-01-20T22:33:08+01:00" level=debug msg="obtained new client token: AADXWqknBej8vtY7E32OrSfchIehrcWariEf4bPD5oagb2Fq5nbQia1TBF/0d7YtRqoyJTGYSJpYANAsXiRZDOveviqxq8o8T3XNwG0eGVGJu10oa00EPY+cKSei4TguFXbDW3tckhBOBjBSRvn5DmRWfgHWjjxNu5+O7K8Jl9OLGP5QXukh/m7IU7FzX9/WrO8ywYgNxhIEHfYvcUx5Qsuzz1Jn0UToW8bOJC13YarcMgzKOG8692oo0Itsxw==" Jan 20 22:33:08 volumio go-librespot[2533]: time="2025-01-20T22:33:08+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 20 22:33:08 volumio go-librespot[2533]: time="2025-01-20T22:33:08+01:00" level=debug msg="completed keyexchange" Jan 20 22:33:09 volumio go-librespot[2533]: time="2025-01-20T22:33:09+01:00" level=debug msg="completed challenge" Jan 20 22:33:09 volumio go-librespot[2533]: time="2025-01-20T22:33:09+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 20 22:33:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 20 22:33:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 20 22:33:09 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Jan 20 22:33:09 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 20 22:33:12 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Jan 20 22:33:12 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 20 22:33:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 20 22:33:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Jan 20 22:33:12 volumio systemd[1]: Stopped go-librespot Daemon. Jan 20 22:33:12 volumio systemd[1]: Started go-librespot Daemon. Jan 20 22:33:12 volumio go-librespot[2542]: Librespot-go daemon starting... Jan 20 22:33:12 volumio go-librespot[2542]: time="2025-01-20T22:33:12+01:00" level=info msg="generated new device id: a5f9ad00b2326e92c87f9d7791a666c3ab11e2a3" Jan 20 22:33:12 volumio go-librespot[2542]: time="2025-01-20T22:33:12+01:00" level=debug msg="stored credentials found for sloam8" Jan 20 22:33:12 volumio go-librespot[2542]: time="2025-01-20T22:33:12+01:00" level=debug msg="obtained new client token: AAB7pdFQLbHikGLqRSpmsRSgeVjdIM1wY85xYm9Jo7fWLStc0srwalFDGCvFCxUZQTkEibZbM3BkQ0+OS12YY+kDXDMCzo9pJvPxQ4BmBCXF4hH5LWBGMmr8VnQkRGltgxk7g8RWzXCzKkUJxefIGPega0VDdIKQDdvX1ShD2nOFJHPBZol1KjQQR+B1MKN6qZ6qSFDCsBgXp1jqJeLdDt9B2DHCrqQbw3PtgrjfSNgAGQ1A8FzokC5XSS72wg==" Jan 20 22:33:12 volumio go-librespot[2542]: time="2025-01-20T22:33:12+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 20 22:33:12 volumio go-librespot[2542]: time="2025-01-20T22:33:12+01:00" level=debug msg="completed keyexchange" Jan 20 22:33:13 volumio go-librespot[2542]: time="2025-01-20T22:33:13+01:00" level=debug msg="completed challenge" Jan 20 22:33:13 volumio go-librespot[2542]: time="2025-01-20T22:33:13+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 20 22:33:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 20 22:33:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 20 22:33:14 volumio volumio[817]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 20 22:33:14 volumio volumio[817]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 20 22:33:14 volumio volumio[817]: info: Retrieving Cloud Streaming UI Jan 20 22:33:14 volumio volumio[817]: info: Getting Tidal Cloud Configuration Jan 20 22:33:14 volumio volumio[817]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 20 22:33:14 volumio volumio[817]: info: Getting Qobuz Cloud Configuration Jan 20 22:33:14 volumio volumio[817]: info: Asking plugin for UI Config Jan 20 22:33:14 volumio volumio[817]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 20 22:33:14 volumio volumio[817]: info: Getting Spotify Cloud Configuration Jan 20 22:33:14 volumio volumio[817]: info: Asking plugin for UI Config Jan 20 22:33:14 volumio volumio[817]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 20 22:33:14 volumio volumio[817]: info: Saving Spotify Acccount Jan 20 22:33:14 volumio volumio[817]: info: Got Tidal Cloud Configuration Jan 20 22:33:14 volumio volumio[817]: info: Got it Jan 20 22:33:14 volumio volumio[817]: info: Got it Jan 20 22:33:14 volumio volumio[817]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Jan 20 22:33:14 volumio volumio[817]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 20 22:33:14 volumio volumio[817]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Jan 20 22:33:14 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jan 20 22:33:14 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 20 22:33:14 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 20 22:33:14 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 20 22:33:14 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 20 22:33:14 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 20 22:33:14 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 20 22:33:14 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 20 22:33:14 volumio volumio[817]: info: CoreCommandRouter::volumioGetBrowseSources Jan 20 22:33:14 volumio volumio[817]: info: CoreCommandRouter::volumioGetBrowseSources Jan 20 22:33:14 volumio volumio[817]: info: CoreCommandRouter::volumioGetBrowseSources Jan 20 22:33:14 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 20 22:33:14 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jan 20 22:33:15 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Jan 20 22:33:15 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 20 22:33:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 20 22:33:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Jan 20 22:33:16 volumio systemd[1]: Stopped go-librespot Daemon. Jan 20 22:33:16 volumio systemd[1]: Started go-librespot Daemon. Jan 20 22:33:16 volumio go-librespot[2572]: Librespot-go daemon starting... Jan 20 22:33:16 volumio go-librespot[2572]: time="2025-01-20T22:33:16+01:00" level=info msg="generated new device id: 4c818e049992464f7346167541a7a6c5df640f2d" Jan 20 22:33:16 volumio go-librespot[2572]: time="2025-01-20T22:33:16+01:00" level=debug msg="stored credentials found for sloam8" Jan 20 22:33:16 volumio go-librespot[2572]: time="2025-01-20T22:33:16+01:00" level=debug msg="obtained new client token: AABWpZlzIhr583oMQIHzcQARklxCFtVUT1ZGyapMOrBxQ8w4wO1DYJtFjq/8i61xvz7mTiOIHzv9F0bBYXu2GnPSpRmzIT8mvAMYHpdnvAAg4ClacVJn8ivGKwYsD6QIFDUyG0NHgtvCZudxdfyjuob6T9sZiulK47JyRj8ary2u+N6QK8JE0mPFLzIMjqjQYx9G8LKvjdhA5iH+RHQGrzotx48CiQej7JLXWfEr4LTVfmD85Rxll6eejVUHAA==" Jan 20 22:33:16 volumio go-librespot[2572]: time="2025-01-20T22:33:16+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 20 22:33:16 volumio go-librespot[2572]: time="2025-01-20T22:33:16+01:00" level=debug msg="completed keyexchange" Jan 20 22:33:17 volumio go-librespot[2572]: time="2025-01-20T22:33:17+01:00" level=debug msg="completed challenge" Jan 20 22:33:17 volumio go-librespot[2572]: time="2025-01-20T22:33:17+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: failed login: BadCredentials" Jan 20 22:33:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 20 22:33:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 20 22:33:18 volumio volumio[817]: info: Initializing connection to go-librespot Websocket Jan 20 22:33:18 volumio volumio[817]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 20 22:33:18 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 20 22:33:19 volumio volumio[817]: info: Disabling MyMusic plugin upnp Jan 20 22:33:19 volumio sudo[2581]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Jan 20 22:33:19 volumio sudo[2581]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 22:33:19 volumio systemd[1]: Stopping UPnP Renderer front-end to MPD... Jan 20 22:33:19 volumio volumio[817]: error: Upnp client error: Error: This socket has been ended by the other party Jan 20 22:33:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 20 22:33:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Jan 20 22:33:20 volumio systemd[1]: Stopped go-librespot Daemon. Jan 20 22:33:20 volumio systemd[1]: Started go-librespot Daemon. Jan 20 22:33:20 volumio go-librespot[2583]: Librespot-go daemon starting... Jan 20 22:33:20 volumio go-librespot[2583]: time="2025-01-20T22:33:20+01:00" level=info msg="generated new device id: 37ea00549325546b645e916d7ca75c6b697d8799" Jan 20 22:33:20 volumio go-librespot[2583]: time="2025-01-20T22:33:20+01:00" level=debug msg="stored credentials found for sloam8" Jan 20 22:33:20 volumio go-librespot[2583]: time="2025-01-20T22:33:20+01:00" level=debug msg="obtained new client token: AADzs0pIRqBuSBEKmouFo4SgKzz3xZeZDnY+n/B5bz/jPou+GGtO8ut24A7ZkrKLihtMjLE3Rn2QiDIqbgngEXxm6lL2AwJ7GAaVzwtY7JvEzbJhZkT09lYEiL4kbSjyjxRzTlFI4pMTtmQhv1r4tm5jX2cLwa0n716Vx/It2FZHh96AGveYoB/lgEqyWhcXyMdaIxlnMA1mK82JceUIet/hLHbik/efLuamyscV0wHWZiMHAgwKsMtBHZTpYA==" Jan 20 22:33:20 volumio go-librespot[2583]: time="2025-01-20T22:33:20+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 20 22:33:20 volumio go-librespot[2583]: time="2025-01-20T22:33:20+01:00" level=debug msg="completed keyexchange" Jan 20 22:33:20 volumio volumio[817]: info: Enabling MyMusic plugin upnp Jan 20 22:33:20 volumio volumio[817]: info: Enabling plugin upnp Jan 20 22:33:20 volumio volumio[817]: info: Loading plugin "upnp"... Jan 20 22:33:20 volumio volumio[817]: info: [1737408800981] Starting Upmpd Daemon Jan 20 22:33:20 volumio volumio[817]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 20 22:33:20 volumio volumio[817]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 20 22:33:20 volumio volumio[817]: Error: listen EADDRINUSE: address already in use :::6599 Jan 20 22:33:20 volumio volumio[817]: at Server.setupListenHandle [as _listen2] (net.js:1331:16) Jan 20 22:33:20 volumio volumio[817]: at listenInCluster (net.js:1379:12) Jan 20 22:33:20 volumio volumio[817]: at Server.listen (net.js:1465:7) Jan 20 22:33:20 volumio volumio[817]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Jan 20 22:33:20 volumio volumio[817]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Jan 20 22:33:20 volumio volumio[817]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Jan 20 22:33:20 volumio volumio[817]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jan 20 22:33:20 volumio volumio[817]: at processTicksAndRejections (internal/process/task_queues.js:77:11) { Jan 20 22:33:20 volumio volumio[817]: code: 'EADDRINUSE', Jan 20 22:33:20 volumio volumio[817]: errno: -98, Jan 20 22:33:20 volumio volumio[817]: syscall: 'listen', Jan 20 22:33:20 volumio volumio[817]: address: '::', Jan 20 22:33:20 volumio volumio[817]: port: 6599 Jan 20 22:33:20 volumio volumio[817]: } Jan 20 22:33:20 volumio volumio[817]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 20 22:33:21 volumio sudo[2622]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-20 22:32 Jan 20 22:33:21 volumio sudo[2622]: 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"