Sep 01 01:26:00 stefans-speaker sudo[23626]: pam_unix(sudo:session): session closed for user root
Sep 01 01:26:00 stefans-speaker volumio[23286]: info: Initializing connection to go-librespot Websocket
Sep 01 01:26:00 stefans-speaker volumio[23286]: error: Cannot start Volumio Streaming Daemon
Sep 01 01:26:00 stefans-speaker volumio[23286]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Sep 01 01:26:00 stefans-speaker volumio[23286]: sudo: unable to resolve host stefans-speaker: System error
Sep 01 01:26:00 stefans-speaker volumio[23286]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Sep 01 01:26:00 stefans-speaker volumio[23286]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Sep 01 01:26:00 stefans-speaker volumio[23286]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Sep 01 01:26:01 stefans-speaker volumio[23286]: info: MyVolumio token set successfully
Sep 01 01:26:01 stefans-speaker volumio[23286]: info: MYVOLUMIO: Adding device
Sep 01 01:26:01 stefans-speaker volumio[23286]: info: MYVOLUMIO: Evaluating Server
Sep 01 01:26:01 stefans-speaker volumio[23286]: info: MyVolumio status changed
Sep 01 01:26:01 stefans-speaker volumio[23286]: info: Streaming services startup
Sep 01 01:26:01 stefans-speaker volumio[23286]: info: Starting Streaming Daemon
Sep 01 01:26:01 stefans-speaker volumio[23286]: info: Removing browser output: myVolumio user plan is not superstar
Sep 01 01:26:01 stefans-speaker volumio[23286]: info: Removing audio output:
Sep 01 01:26:01 stefans-speaker volumio[23286]: info: Stoppping Tunnel 1
Sep 01 01:26:01 stefans-speaker sudo[23653]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:26:01 stefans-speaker sudo[23653]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Sep 01 01:26:01 stefans-speaker sudo[23653]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:26:01 stefans-speaker sudo[23655]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:26:01 stefans-speaker sudo[23655]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service
Sep 01 01:26:01 stefans-speaker sudo[23655]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:26:01 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Sep 01 01:26:01 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 01 01:26:01 stefans-speaker sudo[23653]: pam_unix(sudo:session): session closed for user root
Sep 01 01:26:01 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 01 01:26:01 stefans-speaker volumio[23286]: error: Cannot start Volumio Streaming Daemon
Sep 01 01:26:01 stefans-speaker volumio[23286]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Sep 01 01:26:01 stefans-speaker volumio[23286]: sudo: unable to resolve host stefans-speaker: System error
Sep 01 01:26:01 stefans-speaker volumio[23286]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Sep 01 01:26:01 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:01 stefans-speaker volumio[23286]: info: Setting Geolocation for MyVolumio to eu5
Sep 01 01:26:01 stefans-speaker volumio[23286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:01 stefans-speaker volumio[23286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:01 stefans-speaker volumio[23286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:01 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:01 stefans-speaker go-librespot[23658]: go-librespot daemon starting...
Sep 01 01:26:01 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 01 01:26:01 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 01 01:26:01 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 01 01:26:01 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 01 01:26:01 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 01 01:26:01 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 01 01:26:01 stefans-speaker go-librespot[23659]: time="2026-09-01T01:26:01+02:00" level=info msg="running go-librespot 0.4.0"
Sep 01 01:26:01 stefans-speaker go-librespot[23659]: time="2026-09-01T01:26:01+02:00" level=debug msg="app state loaded"
Sep 01 01:26:01 stefans-speaker sudo[23655]: pam_unix(sudo:session): session closed for user root
Sep 01 01:26:01 stefans-speaker go-librespot[23659]: time="2026-09-01T01:26:01+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Sep 01 01:26:01 stefans-speaker volumio[23286]: info: Remote SSH Stopped
Sep 01 01:26:01 stefans-speaker go-librespot[23659]: time="2026-09-01T01:26:01+02: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]"
Sep 01 01:26:01 stefans-speaker go-librespot[23659]: time="2026-09-01T01:26:01+02: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]"
Sep 01 01:26:01 stefans-speaker go-librespot[23659]: time="2026-09-01T01:26:01+02: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]"
Sep 01 01:26:01 stefans-speaker go-librespot[23659]: time="2026-09-01T01:26:01+02:00" level=info msg="zeroconf server listening on port 32813"
Sep 01 01:26:02 stefans-speaker go-librespot[23659]: time="2026-09-01T01:26:02+02:00" level=debug msg="obtained new client token: AAEABikZx0y/C72WbH5BrH1+WWaPYDHg+0IY3vw+szV0z8skLCLLTCaitOjDADuJFf0m+f0xmL59YWhYQVvqC7sw2VfVoC6sTxASQ1mXqVvXt8TW4NktmVZAhLCe24nQ5tIUv73WvOq62x/CCXYAXpJVI3hwqKvJHwh7kciOQ7gh2DG3J9v6yftmGTxZdSb4BRGbU7ycPpLTaIpDIttktghKpVDqh502JmCy6w6R8mSESJyH1MEppRh2"
Sep 01 01:26:02 stefans-speaker go-librespot[23659]: time="2026-09-01T01:26:02+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Sep 01 01:26:02 stefans-speaker go-librespot[23659]: time="2026-09-01T01:26:02+02:00" level=debug msg="completed keyexchange"
Sep 01 01:26:02 stefans-speaker go-librespot[23659]: time="2026-09-01T01:26:02+02:00" level=debug msg="completed challenge"
Sep 01 01:26:02 stefans-speaker go-librespot[23659]: time="2026-09-01T01:26:02+02:00" level=info msg="authenticated AP" username="31************************cy"
Sep 01 01:26:02 stefans-speaker volumio[23286]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Sep 01 01:26:02 stefans-speaker go-librespot[23659]: time="2026-09-01T01:26:02+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Sep 01 01:26:02 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Sep 01 01:26:02 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Sep 01 01:26:02 stefans-speaker volumio[23286]: info: Updating MyVolumio device info
Sep 01 01:26:02 stefans-speaker volumio[23286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:02 stefans-speaker volumio[23286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:02 stefans-speaker volumio[23286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:02 stefans-speaker volumio[23286]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Sep 01 01:26:03 stefans-speaker volumio[23286]: info: Initializing connection to go-librespot Websocket
Sep 01 01:26:03 stefans-speaker volumio[23286]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Sep 01 01:26:05 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Sep 01 01:26:05 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:05 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:05 stefans-speaker go-librespot[23667]: go-librespot daemon starting...
Sep 01 01:26:05 stefans-speaker go-librespot[23668]: time="2026-09-01T01:26:05+02:00" level=info msg="running go-librespot 0.4.0"
Sep 01 01:26:05 stefans-speaker go-librespot[23668]: time="2026-09-01T01:26:05+02:00" level=debug msg="app state loaded"
Sep 01 01:26:05 stefans-speaker go-librespot[23668]: time="2026-09-01T01:26:05+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Sep 01 01:26:05 stefans-speaker go-librespot[23668]: time="2026-09-01T01:26:05+02: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]"
Sep 01 01:26:05 stefans-speaker go-librespot[23668]: time="2026-09-01T01:26:05+02: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]"
Sep 01 01:26:05 stefans-speaker go-librespot[23668]: time="2026-09-01T01:26:05+02: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]"
Sep 01 01:26:05 stefans-speaker go-librespot[23668]: time="2026-09-01T01:26:05+02:00" level=info msg="zeroconf server listening on port 42387"
Sep 01 01:26:05 stefans-speaker go-librespot[23668]: time="2026-09-01T01:26:05+02:00" level=debug msg="obtained new client token: AAHr6EeXLPqlqWh92fEhR5psqWI3LbBea7rQpPgrSPIa0OVolDtrdxs38Wo19uAGHY/p8mLwY4eKnVF7kefneML1aLGw4g4TKNBviFk8q1W6WQF8svOV0IVKKjrXdAvxUSRDpfOUwwICPHomqsRQGj2J163BEafzaKJqd6LMkoMj1LJi8bbYTsF7Pa+dS79N4/n5q9MfZiPyV9RVR9PHaWfY7kape54dbg9SHNeRbBHwp2QpByailnozlaE="
Sep 01 01:26:05 stefans-speaker go-librespot[23668]: time="2026-09-01T01:26:05+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Sep 01 01:26:06 stefans-speaker go-librespot[23668]: time="2026-09-01T01:26:06+02:00" level=debug msg="completed keyexchange"
Sep 01 01:26:06 stefans-speaker go-librespot[23668]: time="2026-09-01T01:26:06+02:00" level=debug msg="completed challenge"
Sep 01 01:26:06 stefans-speaker volumio[23286]: info: Initializing connection to go-librespot Websocket
Sep 01 01:26:06 stefans-speaker go-librespot[23668]: time="2026-09-01T01:26:06+02:00" level=debug msg="new websocket client"
Sep 01 01:26:06 stefans-speaker volumio[23286]: info: Connection to go-librespot Websocket established
Sep 01 01:26:06 stefans-speaker go-librespot[23668]: time="2026-09-01T01:26:06+02:00" level=info msg="authenticated AP" username="31************************cy"
Sep 01 01:26:06 stefans-speaker go-librespot[23668]: time="2026-09-01T01:26:06+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Sep 01 01:26:06 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Sep 01 01:26:06 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Sep 01 01:26:06 stefans-speaker volumio[23286]: info: Connection to go-librespot Websocket closed
Sep 01 01:26:06 stefans-speaker volumio[23286]: info: MYVOLUMIO: Adding device
Sep 01 01:26:06 stefans-speaker volumio[23286]: info: MYVOLUMIO: Evaluating Server
Sep 01 01:26:06 stefans-speaker volumio[23286]: info: Setting Geolocation for MyVolumio to eu8
Sep 01 01:26:06 stefans-speaker volumio[23286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:06 stefans-speaker volumio[23286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:06 stefans-speaker volumio[23286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:07 stefans-speaker volumio[23286]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Sep 01 01:26:07 stefans-speaker volumio[23286]: info: Updating MyVolumio device info
Sep 01 01:26:07 stefans-speaker volumio[23286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:07 stefans-speaker volumio[23286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:07 stefans-speaker volumio[23286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:08 stefans-speaker volumio[23286]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Sep 01 01:26:09 stefans-speaker volumio[23286]: info: Getting Spotify volume
Sep 01 01:26:09 stefans-speaker volumio[23286]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Sep 01 01:26:09 stefans-speaker volumio[23286]: Error: connect ECONNREFUSED 127.0.0.1:9879
Sep 01 01:26:09 stefans-speaker volumio[23286]:     at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Sep 01 01:26:09 stefans-speaker volumio[23286]:   errno: -111,
Sep 01 01:26:09 stefans-speaker volumio[23286]:   code: 'ECONNREFUSED',
Sep 01 01:26:09 stefans-speaker volumio[23286]:   syscall: 'connect',
Sep 01 01:26:09 stefans-speaker volumio[23286]:   address: '127.0.0.1',
Sep 01 01:26:09 stefans-speaker volumio[23286]:   port: 9879,
Sep 01 01:26:09 stefans-speaker volumio[23286]:   response: undefined
Sep 01 01:26:09 stefans-speaker volumio[23286]: }
Sep 01 01:26:09 stefans-speaker volumio[23286]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Sep 01 01:26:09 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6.
Sep 01 01:26:09 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:09 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:09 stefans-speaker go-librespot[23721]: go-librespot daemon starting...
Sep 01 01:26:09 stefans-speaker go-librespot[23722]: time="2026-09-01T01:26:09+02:00" level=info msg="running go-librespot 0.4.0"
Sep 01 01:26:09 stefans-speaker go-librespot[23722]: time="2026-09-01T01:26:09+02:00" level=debug msg="app state loaded"
Sep 01 01:26:09 stefans-speaker go-librespot[23722]: time="2026-09-01T01:26:09+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Sep 01 01:26:09 stefans-speaker go-librespot[23722]: time="2026-09-01T01:26:09+02: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]"
Sep 01 01:26:09 stefans-speaker go-librespot[23722]: time="2026-09-01T01:26:09+02: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]"
Sep 01 01:26:09 stefans-speaker go-librespot[23722]: time="2026-09-01T01:26:09+02: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]"
Sep 01 01:26:09 stefans-speaker go-librespot[23722]: time="2026-09-01T01:26:09+02:00" level=info msg="zeroconf server listening on port 37845"
Sep 01 01:26:09 stefans-speaker go-librespot[23722]: time="2026-09-01T01:26:09+02:00" level=debug msg="obtained new client token: AAGEshVak+Vyv9WxFgvaf32S7llofeeyXFZ6SeyXfHXlzlJmZwepM86ES20u6ai/I4himrrQk6sXnDpOyeEVXBEmzMNFN/iaarJrWnaTS3aI6BFlVlrDLCYpF680gPBVAm6Nx70/ILi7gDWUwjDELd3Vx8cPt/Ygii8rNcPRWeR8RCD4f29Apj5av4hJEDYGiBbMANO5WqXL2+b7PPk2Xv62NRlsjpcy3kSiM0mjxUFqDEYPROrrupwQx2s="
Sep 01 01:26:09 stefans-speaker go-librespot[23722]: time="2026-09-01T01:26:09+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Sep 01 01:26:09 stefans-speaker go-librespot[23722]: time="2026-09-01T01:26:09+02:00" level=debug msg="completed keyexchange"
Sep 01 01:26:09 stefans-speaker go-librespot[23722]: time="2026-09-01T01:26:09+02:00" level=debug msg="completed challenge"
Sep 01 01:26:09 stefans-speaker sudo[23731]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:26:09 stefans-speaker sudo[23731]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-09-01 01:25'
Sep 01 01:26:09 stefans-speaker sudo[23731]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:26:10 stefans-speaker sudo[23731]: pam_unix(sudo:session): session closed for user root
Sep 01 01:26:10 stefans-speaker volumio[23286]: sudo: unable to resolve host stefans-speaker: System error
Sep 01 01:26:10 stefans-speaker volumio-remote-updater[679]: [2026-09-01 01:26:10] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Sep 01 01:26:10 stefans-speaker volumio-remote-updater[679]: [2026-09-01 01:26:10] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Sep 01 01:26:10 stefans-speaker systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Sep 01 01:26:10 stefans-speaker systemd[1]: volumio.service: Failed with result 'exit-code'.
Sep 01 01:26:10 stefans-speaker systemd[1]: volumio.service: Consumed 33.335s CPU time.
Sep 01 01:26:10 stefans-speaker go-librespot[23722]: time="2026-09-01T01:26:10+02:00" level=info msg="authenticated AP" username="31************************cy"
Sep 01 01:26:10 stefans-speaker systemd[1]: Started dynamicswap.service - dynamicswap service.
Sep 01 01:26:10 stefans-speaker systemd[1]: dynamicswap.service: Deactivated successfully.
Sep 01 01:26:10 stefans-speaker go-librespot[23722]: time="2026-09-01T01:26:10+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Sep 01 01:26:10 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Sep 01 01:26:10 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Sep 01 01:26:10 stefans-speaker systemd[1]: volumio.service: Scheduled restart job, restart counter is at 324.
Sep 01 01:26:10 stefans-speaker systemd[1]: Started dynamicswap.service - dynamicswap service.
Sep 01 01:26:10 stefans-speaker systemd[1]: Stopped volumio.service - Volumio Backend Module.
Sep 01 01:26:10 stefans-speaker systemd[1]: volumio.service: Consumed 33.335s CPU time.
Sep 01 01:26:10 stefans-speaker systemd[1]: Started volumio.service - Volumio Backend Module.
Sep 01 01:26:10 stefans-speaker systemd[1]: dynamicswap.service: Deactivated successfully.
Sep 01 01:26:12 stefans-speaker volumio[23743]: info: -------------------------------------------
Sep 01 01:26:12 stefans-speaker volumio[23743]: info: -----            Volumio3              ----
Sep 01 01:26:12 stefans-speaker volumio[23743]: info: -------------------------------------------
Sep 01 01:26:12 stefans-speaker volumio[23743]: info: -----          System startup          ----
Sep 01 01:26:12 stefans-speaker volumio[23743]: info: -------------------------------------------
Sep 01 01:26:13 stefans-speaker volumio[23743]: info: MYVOLUMIO Environment detected
Sep 01 01:26:13 stefans-speaker volumio[23743]: info: Plugin folders cleanup
Sep 01 01:26:13 stefans-speaker volumio[23743]: info: Scanning into folder /volumio/app/plugins/
Sep 01 01:26:13 stefans-speaker volumio[23743]: info: Scanning category audio_interface
Sep 01 01:26:13 stefans-speaker volumio[23743]: info: Scanning category miscellanea
Sep 01 01:26:13 stefans-speaker volumio[23743]: info: Scanning category music_service
Sep 01 01:26:13 stefans-speaker volumio[23743]: info: Scanning category plugins.json
Sep 01 01:26:13 stefans-speaker volumio[23743]: info: Scanning category system_controller
Sep 01 01:26:13 stefans-speaker volumio[23743]: info: Scanning category user_interface
Sep 01 01:26:13 stefans-speaker volumio[23743]: info: Scanning into folder /data/plugins/
Sep 01 01:26:13 stefans-speaker volumio[23743]: info: Scanning category music_service
Sep 01 01:26:13 stefans-speaker volumio[23743]: info: Plugin folders cleanup completed
Sep 01 01:26:13 stefans-speaker volumio[23743]: info: -------------------------------------------
Sep 01 01:26:13 stefans-speaker volumio[23743]: info: -----      Core plugins startup        ----
Sep 01 01:26:13 stefans-speaker volumio[23743]: info: -------------------------------------------
Sep 01 01:26:13 stefans-speaker volumio[23743]: info: Loading plugins from folder /volumio/app/plugins/
Sep 01 01:26:13 stefans-speaker volumio[23743]: info: Adding plugin upnp to MyMusic Plugins
Sep 01 01:26:13 stefans-speaker volumio[23743]: info: Adding plugin airplay_emulation to MyMusic Plugins
Sep 01 01:26:13 stefans-speaker volumio[23743]: info: Adding plugin upnp_browser to MyMusic Plugins
Sep 01 01:26:13 stefans-speaker volumio[23743]: info: Loading plugins from folder /data/plugins/
Sep 01 01:26:13 stefans-speaker volumio[23743]: info: Loading plugin "system"...
Sep 01 01:26:13 stefans-speaker volumio[23743]: info: Loading plugin "appearance"...
Sep 01 01:26:13 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Sep 01 01:26:13 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:13 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:13 stefans-speaker go-librespot[23773]: go-librespot daemon starting...
Sep 01 01:26:13 stefans-speaker go-librespot[23774]: time="2026-09-01T01:26:13+02:00" level=info msg="running go-librespot 0.4.0"
Sep 01 01:26:13 stefans-speaker go-librespot[23774]: time="2026-09-01T01:26:13+02:00" level=debug msg="app state loaded"
Sep 01 01:26:13 stefans-speaker go-librespot[23774]: time="2026-09-01T01:26:13+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Sep 01 01:26:13 stefans-speaker go-librespot[23774]: time="2026-09-01T01:26:13+02: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]"
Sep 01 01:26:13 stefans-speaker go-librespot[23774]: time="2026-09-01T01:26:13+02: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]"
Sep 01 01:26:13 stefans-speaker go-librespot[23774]: time="2026-09-01T01:26:13+02: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]"
Sep 01 01:26:13 stefans-speaker go-librespot[23774]: time="2026-09-01T01:26:13+02:00" level=info msg="zeroconf server listening on port 46675"
Sep 01 01:26:14 stefans-speaker go-librespot[23774]: time="2026-09-01T01:26:14+02:00" level=debug msg="obtained new client token: AAHqu6xrh3Ta3D20Llvu+0ol3PQsABMglfGLDDfLrkYexcnQ9YpCPMMuuJ/Y+TWzc6UHaAqGiP+0FY92WWEyrnr8lcp5E5YTCzS61mU5bK3UF1Bio1EDQ9Px8WoijUjDEyM52+QhCRQQTHsNgmLZzy4qDZog3dcjZ3NWzcmelL9JN9UwqA0q8mm+qc55+BClH/SIMz0dkoc38sxvkORpBowTDXu9bMRJsZ4KooT8b81I/Zo1gCI0I3CQ"
Sep 01 01:26:14 stefans-speaker go-librespot[23774]: time="2026-09-01T01:26:14+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Sep 01 01:26:14 stefans-speaker go-librespot[23774]: time="2026-09-01T01:26:14+02:00" level=debug msg="completed keyexchange"
Sep 01 01:26:14 stefans-speaker go-librespot[23774]: time="2026-09-01T01:26:14+02:00" level=debug msg="completed challenge"
Sep 01 01:26:14 stefans-speaker go-librespot[23774]: time="2026-09-01T01:26:14+02:00" level=info msg="authenticated AP" username="31************************cy"
Sep 01 01:26:14 stefans-speaker go-librespot[23774]: time="2026-09-01T01:26:14+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Sep 01 01:26:14 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Sep 01 01:26:14 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Sep 01 01:26:14 stefans-speaker volumio[23743]: info: Loading plugin "network"...
Sep 01 01:26:14 stefans-speaker volumio[23743]: info: Refreshing Cached IP Addresses
Sep 01 01:26:14 stefans-speaker sudo[23783]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:26:14 stefans-speaker volumio[23743]: info: Loading plugin "services"...
Sep 01 01:26:14 stefans-speaker sudo[23785]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:26:14 stefans-speaker volumio[23743]: info: Loading plugin "alsa_controller"...
Sep 01 01:26:14 stefans-speaker sudo[23783]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Sep 01 01:26:14 stefans-speaker sudo[23783]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:26:14 stefans-speaker sudo[23785]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 01 01:26:14 stefans-speaker sudo[23785]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:26:14 stefans-speaker sudo[23783]: pam_unix(sudo:session): session closed for user root
Sep 01 01:26:14 stefans-speaker sudo[23785]: pam_unix(sudo:session): session closed for user root
Sep 01 01:26:14 stefans-speaker sudo[23792]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:26:14 stefans-speaker sudo[23792]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Sep 01 01:26:14 stefans-speaker sudo[23792]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:26:14 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Sep 01 01:26:14 stefans-speaker volumio[23743]: info: Loading plugin "wizard"...
Sep 01 01:26:14 stefans-speaker volumio[23743]: info: Loading plugin "networkfs"...
Sep 01 01:26:14 stefans-speaker volumio[23743]: info: Starting Udev Watcher for removable devices
Sep 01 01:26:14 stefans-speaker volumio[23743]: info: Ignoring mount for partition: boot
Sep 01 01:26:14 stefans-speaker volumio[23743]: info: Ignoring mount for partition: volumio
Sep 01 01:26:14 stefans-speaker volumio[23743]: info: Ignoring mount for partition: volumio_data
Sep 01 01:26:14 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Sep 01 01:26:14 stefans-speaker volumio[23743]: info: Loading plugin "volumio_command_line_client"...
Sep 01 01:26:14 stefans-speaker volumio[23743]: info: Loading plugin "upnp"...
Sep 01 01:26:14 stefans-speaker volumio[23743]: info: [1788218774832] Starting Upmpd Daemon
Sep 01 01:26:14 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Sep 01 01:26:14 stefans-speaker volumio[23743]: info: Loading plugin "my_music"...
Sep 01 01:26:14 stefans-speaker volumio[23743]: info: Loading plugin "mpd"...
Sep 01 01:26:15 stefans-speaker volumio[23743]: info: Loading plugin "upnp_browser"...
Sep 01 01:26:15 stefans-speaker volumio-remote-updater[679]: [2026-09-01 01:26:15] [connect] Successful connection
Sep 01 01:26:16 stefans-speaker volumio[23743]: info: Starting UPNP Browser
Sep 01 01:26:16 stefans-speaker volumio[23743]: info: Loading plugin "alarm-clock"...
Sep 01 01:26:16 stefans-speaker volumio[23743]: info: Loading plugin "airplay_emulation"...
Sep 01 01:26:16 stefans-speaker volumio[23743]: info: Starting Shairport Sync
Sep 01 01:26:16 stefans-speaker volumio[23743]: info: Loading plugin "last_100"...
Sep 01 01:26:16 stefans-speaker volumio[23743]: info: Loading plugin "webradio"...
Sep 01 01:26:17 stefans-speaker volumio[23743]: info: Loading plugin "i2s_dacs"...
Sep 01 01:26:17 stefans-speaker volumio[23743]: info: I2S DAC not set, start Auto-detection
Sep 01 01:26:17 stefans-speaker volumio[23743]: info: Loading plugin "volumiodiscovery"...
Sep 01 01:26:17 stefans-speaker volumio[23743]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Sep 01 01:26:17 stefans-speaker volumio[23743]: *** WARNING *** Please fix your application to use the native API of Avahi!
Sep 01 01:26:17 stefans-speaker volumio[23743]: *** WARNING *** For more information see 
Sep 01 01:26:17 stefans-speaker volumio[23743]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Sep 01 01:26:17 stefans-speaker volumio[23743]: *** WARNING *** Please fix your application to use the native API of Avahi!
Sep 01 01:26:17 stefans-speaker volumio[23743]: *** WARNING *** For more information see 
Sep 01 01:26:17 stefans-speaker node[23743]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Sep 01 01:26:17 stefans-speaker node[23743]: *** WARNING *** Please fix your application to use the native API of Avahi!
Sep 01 01:26:17 stefans-speaker node[23743]: *** WARNING *** For more information see 
Sep 01 01:26:17 stefans-speaker node[23743]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Sep 01 01:26:17 stefans-speaker node[23743]: *** WARNING *** Please fix your application to use the native API of Avahi!
Sep 01 01:26:17 stefans-speaker node[23743]: *** WARNING *** For more information see 
Sep 01 01:26:17 stefans-speaker volumio[23743]: info: Applying required configuration parameters for plugin volumiodiscovery
Sep 01 01:26:17 stefans-speaker volumio[23743]: info: Discovery: Started advertising with name: Stefan’s Speaker
Sep 01 01:26:17 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Sep 01 01:26:17 stefans-speaker volumio[23743]: info: Loading plugin "spop"...
Sep 01 01:26:17 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8.
Sep 01 01:26:17 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:17 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:17 stefans-speaker go-librespot[23818]: go-librespot daemon starting...
Sep 01 01:26:17 stefans-speaker go-librespot[23819]: time="2026-09-01T01:26:17+02:00" level=info msg="running go-librespot 0.4.0"
Sep 01 01:26:17 stefans-speaker go-librespot[23819]: time="2026-09-01T01:26:17+02:00" level=debug msg="app state loaded"
Sep 01 01:26:17 stefans-speaker go-librespot[23819]: time="2026-09-01T01:26:17+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Sep 01 01:26:17 stefans-speaker sudo[23792]: pam_unix(sudo:session): session closed for user root
Sep 01 01:26:18 stefans-speaker go-librespot[23819]: time="2026-09-01T01:26:18+02: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]"
Sep 01 01:26:18 stefans-speaker go-librespot[23819]: time="2026-09-01T01:26:18+02: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]"
Sep 01 01:26:18 stefans-speaker go-librespot[23819]: time="2026-09-01T01:26:18+02: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]"
Sep 01 01:26:18 stefans-speaker go-librespot[23819]: time="2026-09-01T01:26:18+02:00" level=info msg="zeroconf server listening on port 33503"
Sep 01 01:26:18 stefans-speaker volumio[23743]: info: Loading plugin "ytcr"...
Sep 01 01:26:18 stefans-speaker go-librespot[23819]: time="2026-09-01T01:26:18+02:00" level=debug msg="obtained new client token: AAHC8++9Y3Ud1NYKy22+2lBq85USHGgE0HCc1/7Sjc6mILywea98JaWrrjqZTt/83kS7U7OPcpeLpG/0CNRDrEWsuTtquyawOo2F6ljAwITpbb2QKYS2oGb5TxetUhk2pVMPPMliAx7htUgmO94+YvI7mHpUPZkYpuPqEPAhxg+fE5wsYAa+B+POIeUHGMRa155OZLMPV75qEDis9RNNA40baAfElsO5yxPt+4tbizXwbsSyn5UXyFgZ"
Sep 01 01:26:18 stefans-speaker go-librespot[23819]: time="2026-09-01T01:26:18+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Sep 01 01:26:18 stefans-speaker go-librespot[23819]: time="2026-09-01T01:26:18+02:00" level=debug msg="completed keyexchange"
Sep 01 01:26:18 stefans-speaker go-librespot[23819]: time="2026-09-01T01:26:18+02:00" level=debug msg="completed challenge"
Sep 01 01:26:18 stefans-speaker go-librespot[23819]: time="2026-09-01T01:26:18+02:00" level=info msg="authenticated AP" username="31************************cy"
Sep 01 01:26:18 stefans-speaker go-librespot[23819]: time="2026-09-01T01:26:18+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Sep 01 01:26:18 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Sep 01 01:26:18 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Sep 01 01:26:19 stefans-speaker volumio[23743]: info: Loading plugin "outputs"...
Sep 01 01:26:19 stefans-speaker volumio[23743]: info: Loading plugin "albumart"...
Sep 01 01:26:19 stefans-speaker volumio[23743]: info: Plugin example_plugin is not enabled
Sep 01 01:26:19 stefans-speaker volumio[23743]: info: Loading plugin "inputs"...
Sep 01 01:26:19 stefans-speaker volumio[23743]: info: Loading plugin "updater_comm"...
Sep 01 01:26:19 stefans-speaker volumio[23743]: info: Plugin mpdemulation is not enabled
Sep 01 01:26:19 stefans-speaker volumio[23743]: info: Loading plugin "rest_api"...
Sep 01 01:26:19 stefans-speaker volumio[23743]: info: Loading plugin "websocket"...
Sep 01 01:26:19 stefans-speaker volumio[23743]: info: Starting Socket.io Server version 1.7.4
Sep 01 01:26:19 stefans-speaker volumio[23743]: info: Loading i18n strings for locale nl
Sep 01 01:26:19 stefans-speaker volumio[23743]: Updating browse sources language
Sep 01 01:26:19 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreCommandRouter::initPlayerControls
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Sep 01 01:26:20 stefans-speaker volumio[23743]: Express server listening on port 3000
Sep 01 01:26:20 stefans-speaker volumio[23743]:  [Metrics]  WebUI:  8s 108.71ms 
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreStateMachine::resetVolumioState
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreStateMachine::getcurrentVolume
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreCommandRouter::volumioRetrievevolume
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: Cannot read play queue from file
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: Volumio Network Manager: Network status updated: 2
Sep 01 01:26:20 stefans-speaker volumio[23827]: Forking 3 albumart workers
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: VolumeController:: Volume=70 Mute =false
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreStateMachine::pushState
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CorePlayQueue::getTrack 0
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreCommandRouter::volumioPushState
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreStateMachine::updateTrackBlock
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CorePlayQueue::getTrackBlock
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreCommandRouter::volumioRetrievevolume
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreStateMachine::setRepeat null single undefined
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreStateMachine::pushState
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CorePlayQueue::getTrack 0
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreCommandRouter::volumioPushState
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreStateMachine::setRandom null
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreStateMachine::pushState
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CorePlayQueue::getTrack 0
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreCommandRouter::volumioPushState
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: Setting Device type: Raspberry PI
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: VolumeController:: Volume=70 Mute =false
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreStateMachine::pushState
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CorePlayQueue::getTrack 0
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreCommandRouter::volumioPushState
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: Completed loading Core Plugins
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: Preparing to generate the ALSA configuration file
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: Discovery: adding a312d0fa-c0eb-45ad-a25b-79fcdf237e8a
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: Discovery: Found device Stefan’s Speaker
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreCommandRouter::volumioGetState
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CorePlayQueue::getTrack 0
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: Discovery: this is already registered,  a312d0fa-c0eb-45ad-a25b-79fcdf237e8a
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: Discovery: Found device Stefan’s Speaker
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreCommandRouter::volumioGetState
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CorePlayQueue::getTrack 0
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: Asound.conf file unchanged, so no further update is needed
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: Output device has changed, restarting MPD
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: Output device has changed, restarting Shairport Sync
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:20 stefans-speaker sudo[23882]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:26:20 stefans-speaker sudo[23884]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:26:20 stefans-speaker sudo[23882]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Sep 01 01:26:20 stefans-speaker sudo[23884]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Sep 01 01:26:20 stefans-speaker sudo[23884]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:26:20 stefans-speaker sudo[23882]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:26:20 stefans-speaker sudo[23882]: pam_unix(sudo:session): session closed for user root
Sep 01 01:26:20 stefans-speaker volumio[23743]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Sep 01 01:26:21 stefans-speaker volumio[23743]: info: ___________ START PLUGINS ___________
Sep 01 01:26:21 stefans-speaker volumio[23743]: info: ControllerMpd::onStart: Initializing MPD
Sep 01 01:26:21 stefans-speaker volumio[23743]: info: Creating MPD Configuration file
Sep 01 01:26:21 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Sep 01 01:26:21 stefans-speaker volumio[23743]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Sep 01 01:26:21 stefans-speaker volumio[23743]: info: [1788218781041] CoreMusicLibrary::Adding element Media Servers
Sep 01 01:26:21 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 01 01:26:21 stefans-speaker volumio[23743]: info: UPNP Browser: Client initialized successfully
Sep 01 01:26:21 stefans-speaker systemd[1]: Stopping mpd.service - Music Player Daemon...
Sep 01 01:26:21 stefans-speaker sudo[23893]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:26:21 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:21 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:21 stefans-speaker sudo[23893]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Sep 01 01:26:21 stefans-speaker sudo[23893]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:26:21 stefans-speaker sudo[23893]: pam_unix(sudo:session): session closed for user root
Sep 01 01:26:21 stefans-speaker sudo[23894]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:26:21 stefans-speaker volumio[23743]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Sep 01 01:26:21 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:21 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:21 stefans-speaker systemd[1]: mpd.service: Deactivated successfully.
Sep 01 01:26:21 stefans-speaker systemd[1]: Stopped mpd.service - Music Player Daemon.
Sep 01 01:26:21 stefans-speaker systemd[1]: mpd.service: Consumed 4.416s CPU time.
Sep 01 01:26:21 stefans-speaker systemd[1]: mpd.socket: Deactivated successfully.
Sep 01 01:26:21 stefans-speaker systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Sep 01 01:26:21 stefans-speaker systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Sep 01 01:26:21 stefans-speaker sudo[23894]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Sep 01 01:26:21 stefans-speaker sudo[23894]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:26:21 stefans-speaker volumio[23743]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Sep 01 01:26:21 stefans-speaker volumio[23743]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Sep 01 01:26:21 stefans-speaker volumio[23743]: info: [1788218781225] CoreMusicLibrary::Adding element Last_100
Sep 01 01:26:21 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 01 01:26:21 stefans-speaker systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Sep 01 01:26:21 stefans-speaker systemd[1]: Starting mpd.service - Music Player Daemon...
Sep 01 01:26:21 stefans-speaker volumio[23743]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Sep 01 01:26:21 stefans-speaker volumio[23743]: info: [1788218781243] CoreMusicLibrary::Adding element Webradio
Sep 01 01:26:21 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 01 01:26:21 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Sep 01 01:26:21 stefans-speaker systemd[1]: mpd.service: Deactivated successfully.
Sep 01 01:26:21 stefans-speaker systemd[1]: Stopped mpd.service - Music Player Daemon.
Sep 01 01:26:21 stefans-speaker volumio[23743]: info: Initializing BBC Radios
Sep 01 01:26:21 stefans-speaker systemd[1]: mpd.socket: Deactivated successfully.
Sep 01 01:26:21 stefans-speaker systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Sep 01 01:26:21 stefans-speaker systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Sep 01 01:26:21 stefans-speaker systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Sep 01 01:26:21 stefans-speaker systemd[1]: Starting mpd.service - Music Player Daemon...
Sep 01 01:26:21 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Sep 01 01:26:21 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:21 stefans-speaker volumio[23743]: info: Creating Spotify config file
Sep 01 01:26:21 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:21 stefans-speaker sudo[23910]:     root : unable to resolve host stefans-speaker: System error
Sep 01 01:26:21 stefans-speaker sudo[23910]: sudo: unable to resolve host stefans-speaker: System error
Sep 01 01:26:21 stefans-speaker sudo[23910]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Sep 01 01:26:21 stefans-speaker sudo[23910]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Sep 01 01:26:21 stefans-speaker sudo[23910]: pam_unix(sudo:session): session closed for user root
Sep 01 01:26:21 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9.
Sep 01 01:26:21 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:21 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:21 stefans-speaker go-librespot[23924]: go-librespot daemon starting...
Sep 01 01:26:21 stefans-speaker go-librespot[23925]: time="2026-09-01T01:26:21+02:00" level=info msg="running go-librespot 0.4.0"
Sep 01 01:26:22 stefans-speaker volumio[23743]: info: Volumio Calling Home
Sep 01 01:26:22 stefans-speaker go-librespot[23925]: time="2026-09-01T01:26:22+02:00" level=info msg="zeroconf server listening on port 46129"
Sep 01 01:26:22 stefans-speaker volumio[23843]: Starting albumart workers
Sep 01 01:26:22 stefans-speaker volumio[23844]: Starting albumart workers
Sep 01 01:26:22 stefans-speaker volumio[23845]: Starting albumart workers
Sep 01 01:26:22 stefans-speaker volumio[23743]: info: MPD Permissions set
Sep 01 01:26:22 stefans-speaker volumio[23743]: info: MPD Permissions set
Sep 01 01:26:22 stefans-speaker volumio[23743]: info: Volumio called home
Sep 01 01:26:22 stefans-speaker volumio[23743]: info: Spotify config file written
Sep 01 01:26:22 stefans-speaker sudo[23937]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:26:22 stefans-speaker sudo[23937]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Sep 01 01:26:22 stefans-speaker sudo[23937]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:26:22 stefans-speaker volumio[23743]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1
Sep 01 01:26:22 stefans-speaker systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon...
Sep 01 01:26:22 stefans-speaker systemd[1]: go-librespot-daemon.service: Deactivated successfully.
Sep 01 01:26:22 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:22 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:22 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:23 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:23 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:23 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:23 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:23 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:23 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:23 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:23 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:23 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:23 stefans-speaker go-librespot[23939]: go-librespot daemon starting...
Sep 01 01:26:23 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:23 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:23 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:23 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:23 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:23 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:23 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:23 stefans-speaker sudo[23937]: pam_unix(sudo:session): session closed for user root
Sep 01 01:26:23 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:23 stefans-speaker go-librespot[23945]: time="2026-09-01T01:26:23+02:00" level=info msg="running go-librespot 0.4.0"
Sep 01 01:26:23 stefans-speaker go-librespot[23945]: time="2026-09-01T01:26:23+02:00" level=debug msg="app state loaded"
Sep 01 01:26:23 stefans-speaker go-librespot[23945]: time="2026-09-01T01:26:23+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Sep 01 01:26:23 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:23 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:23 stefans-speaker volumio[23743]: info: No need to fix Spotify hosts
Sep 01 01:26:23 stefans-speaker go-librespot[23945]: time="2026-09-01T01:26:23+02: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]"
Sep 01 01:26:23 stefans-speaker go-librespot[23945]: time="2026-09-01T01:26:23+02: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]"
Sep 01 01:26:23 stefans-speaker go-librespot[23945]: time="2026-09-01T01:26:23+02: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]"
Sep 01 01:26:23 stefans-speaker go-librespot[23945]: time="2026-09-01T01:26:23+02:00" level=info msg="zeroconf server listening on port 44473"
Sep 01 01:26:23 stefans-speaker go-librespot[23945]: time="2026-09-01T01:26:23+02:00" level=debug msg="obtained new client token: AAHDCWgEh7SKPaEdmY+uoOCnI5NoykGbofOF+b2+n3ny3tD8oW6263U0j63d9OsjcIYIfePbpfc56mMRD5nREPVBtdrhhJblDAHWij2sMmUxsMhf39IXu5thKjKPoBdWq/DTIIK3CABnxt+Q4pp+SIhU62p2R35uTQUFm6sLXS4k/5v3xDzmsoLHSB9HXXyDph76nRwNqvaQ4CNqqAzLQTjXVa4Gx8tEIcxe9WcyuEkgIDMJQYEHzvwlBAU="
Sep 01 01:26:23 stefans-speaker go-librespot[23945]: time="2026-09-01T01:26:23+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Sep 01 01:26:23 stefans-speaker go-librespot[23945]: time="2026-09-01T01:26:23+02:00" level=debug msg="completed keyexchange"
Sep 01 01:26:23 stefans-speaker go-librespot[23945]: time="2026-09-01T01:26:23+02:00" level=debug msg="completed challenge"
Sep 01 01:26:23 stefans-speaker go-librespot[23945]: time="2026-09-01T01:26:23+02:00" level=info msg="authenticated AP" username="31************************cy"
Sep 01 01:26:23 stefans-speaker go-librespot[23945]: time="2026-09-01T01:26:23+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Sep 01 01:26:23 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Sep 01 01:26:23 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Sep 01 01:26:24 stefans-speaker volumio[23743]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Sep 01 01:26:24 stefans-speaker volumio[23743]: SPOTIFY: BQASb0OgiqovVTEnW674Pj1xFVAK4fMQptFCy1P6aSUHDfJZWCus5TkMKlb9GaITjivi_hZiiakf1kA9XIu9zoeLM3GrAvIiZqBYhSWgtiKuS3q_F_d_g4837CNvQyoC1_onJIBo24OKloFNDi4OY1lTl4njsqHmni8Th1Grz_G20_yrjFYkzmP_5G_0YKHL0OvGwbweEIdpPuhIB-Sg8pug_9iPsMDSJqE_8wOWSh5oLnicnm2bph-ZqNQ-HziZZNtzwLGi7oAnPbaFLdmbR3qcib872r5ItjOHGGgIL59ivUvXrJW2qbpgHHuEzzE
Sep 01 01:26:24 stefans-speaker volumio[23743]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Sep 01 01:26:24 stefans-speaker volumio[23743]: info: New Spotify access token = BQASb0OgiqovVTEnW674Pj1xFVAK4fMQptFCy1P6aSUHDfJZWCus5TkMKlb9GaITjivi_hZiiakf1kA9XIu9zoeLM3GrAvIiZqBYhSWgtiKuS3q_F_d_g4837CNvQyoC1_onJIBo24OKloFNDi4OY1lTl4njsqHmni8Th1Grz_G20_yrjFYkzmP_5G_0YKHL0OvGwbweEIdpPuhIB-Sg8pug_9iPsMDSJqE_8wOWSh5oLnicnm2bph-ZqNQ-HziZZNtzwLGi7oAnPbaFLdmbR3qcib872r5ItjOHGGgIL59ivUvXrJW2qbpgHHuEzzE
Sep 01 01:26:24 stefans-speaker volumio[23743]: info: Spotify credentials grant success - running version from March 24, 2019
Sep 01 01:26:24 stefans-speaker volumio[23743]: info: Starting Shairport Sync
Sep 01 01:26:24 stefans-speaker volumio[23743]: info: Starting Shairport Sync
Sep 01 01:26:24 stefans-speaker volumio[23743]: info: Starting Shairport Sync
Sep 01 01:26:24 stefans-speaker sudo[23977]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:26:24 stefans-speaker sudo[23979]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:26:24 stefans-speaker sudo[23977]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Sep 01 01:26:24 stefans-speaker sudo[23977]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:26:24 stefans-speaker sudo[23979]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Sep 01 01:26:24 stefans-speaker sudo[23979]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:26:24 stefans-speaker sudo[23981]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:26:24 stefans-speaker systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Sep 01 01:26:24 stefans-speaker systemd[1]: shairport-sync.service: Deactivated successfully.
Sep 01 01:26:24 stefans-speaker systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Sep 01 01:26:24 stefans-speaker systemd[1]: shairport-sync.service: Consumed 1.879s CPU time.
Sep 01 01:26:24 stefans-speaker sudo[23981]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Sep 01 01:26:24 stefans-speaker sudo[23981]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:26:24 stefans-speaker systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Sep 01 01:26:24 stefans-speaker sudo[23977]: pam_unix(sudo:session): session closed for user root
Sep 01 01:26:24 stefans-speaker volumio[23743]: info: Shairport-Sync Started
Sep 01 01:26:24 stefans-speaker volumio[23743]: Error adding Membership: Error: addMembership EINVAL
Sep 01 01:26:24 stefans-speaker volumio[23743]: info: CoreCommandRouter::volumioGetState
Sep 01 01:26:24 stefans-speaker volumio[23743]: info: CorePlayQueue::getTrack 0
Sep 01 01:26:24 stefans-speaker systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Sep 01 01:26:24 stefans-speaker systemd[1]: shairport-sync.service: Deactivated successfully.
Sep 01 01:26:24 stefans-speaker systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Sep 01 01:26:24 stefans-speaker systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Sep 01 01:26:24 stefans-speaker sudo[23981]: pam_unix(sudo:session): session closed for user root
Sep 01 01:26:24 stefans-speaker sudo[23979]: pam_unix(sudo:session): session closed for user root
Sep 01 01:26:24 stefans-speaker volumio[23743]: info: Shairport-Sync Started
Sep 01 01:26:24 stefans-speaker volumio[23743]: info: Shairport-Sync Started
Sep 01 01:26:24 stefans-speaker volumio[23743]: SPOTIFY: User informations: {"account_id":"zltuAJDW9c","country":"RO","display_name":"emanueluss","email":"emanuel.grecescu@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31mmtxvuufe76qdkk6caepwk3fcy"},"followers":{"href":null,"total":3},"href":"https://api.spotify.com/v1/users/31mmtxvuufe76qdkk6caepwk3fcy","id":"31mmtxvuufe76qdkk6caepwk3fcy","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee852e7ddfcb02af85c1462f3412","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b822e7ddfcb02af85c1462f3412","width":64}],"product":"premium","type":"user","uri":"spotify:user:31mmtxvuufe76qdkk6caepwk3fcy"}
Sep 01 01:26:24 stefans-speaker volumio[23743]: info: Spotify Successfully logged in
Sep 01 01:26:24 stefans-speaker volumio[23743]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Sep 01 01:26:24 stefans-speaker volumio[23743]: info: [1788218784544] CoreMusicLibrary::Adding element Spotify
Sep 01 01:26:24 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 01 01:26:24 stefans-speaker volumio[23743]: Cannot find translation for source Spotify
Sep 01 01:26:24 stefans-speaker sudo[24017]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:26:24 stefans-speaker sudo[24019]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:26:24 stefans-speaker sudo[24017]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Sep 01 01:26:24 stefans-speaker sudo[24019]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 01 01:26:24 stefans-speaker sudo[24017]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:26:24 stefans-speaker sudo[24019]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:26:24 stefans-speaker sudo[24017]: pam_unix(sudo:session): session closed for user root
Sep 01 01:26:24 stefans-speaker sudo[24019]: pam_unix(sudo:session): session closed for user root
Sep 01 01:26:25 stefans-speaker sudo[24023]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:26:25 stefans-speaker sudo[24023]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Sep 01 01:26:25 stefans-speaker sudo[24023]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:26:25 stefans-speaker volumio[23743]: info: [yt-cast-receiver] DIAL server listening on port 8098
Sep 01 01:26:25 stefans-speaker volumio[23743]: info: CoreCommandRouter::volumioRetrievevolume
Sep 01 01:26:25 stefans-speaker sudo[24023]: pam_unix(sudo:session): session closed for user root
Sep 01 01:26:25 stefans-speaker volumio[23743]: info: Upmpdcli Daemon Started
Sep 01 01:26:25 stefans-speaker volumio[23743]: info: VolumeController:: Volume=70 Mute =false
Sep 01 01:26:25 stefans-speaker volumio[23743]: info: CoreCommandRouter::volumioGetState
Sep 01 01:26:25 stefans-speaker volumio[23743]: info: CorePlayQueue::getTrack 0
Sep 01 01:26:25 stefans-speaker volumio[23743]: info: CoreStateMachine::pushState
Sep 01 01:26:25 stefans-speaker volumio[23743]: info: CorePlayQueue::getTrack 0
Sep 01 01:26:25 stefans-speaker volumio[23743]: info: CoreCommandRouter::volumioPushState
Sep 01 01:26:26 stefans-speaker mpd[23923]: 2026-09-01T01:26:26 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Sep 01 01:26:26 stefans-speaker systemd[1]: Started mpd.service - Music Player Daemon.
Sep 01 01:26:26 stefans-speaker sudo[23894]: pam_unix(sudo:session): session closed for user root
Sep 01 01:26:26 stefans-speaker sudo[23884]: pam_unix(sudo:session): session closed for user root
Sep 01 01:26:26 stefans-speaker volumio[23743]: error: MPD error: The expression evaluated to a falsy value:
Sep 01 01:26:26 stefans-speaker volumio[23743]:   assert.ok(self.idling)
Sep 01 01:26:26 stefans-speaker volumio[23743]: error: The expression evaluated to a falsy value:
Sep 01 01:26:26 stefans-speaker volumio[23743]:   assert.ok(self.idling)
Sep 01 01:26:26 stefans-speaker volumio[23743]: error: updateQueue error: null
Sep 01 01:26:26 stefans-speaker volumio[23743]: info: MPD running with PID23923
Sep 01 01:26:26 stefans-speaker volumio[23743]:  ,establishing connection
Sep 01 01:26:26 stefans-speaker volumio[23743]: info: Completed starting Core Plugins
Sep 01 01:26:26 stefans-speaker volumio[23743]: info: -------------------------------------------
Sep 01 01:26:26 stefans-speaker volumio[23743]: info: -----    MyVolumio plugins startup     ----
Sep 01 01:26:26 stefans-speaker volumio[23743]: info: -------------------------------------------
Sep 01 01:26:26 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Fetching plans data....
Sep 01 01:26:26 stefans-speaker volumio[23743]: error: updateQueue error: null
Sep 01 01:26:27 stefans-speaker volumio[23743]: info: go-librespot daemon successfully initialized
Sep 01 01:26:27 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Sep 01 01:26:27 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:27 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:27 stefans-speaker go-librespot[24033]: go-librespot daemon starting...
Sep 01 01:26:27 stefans-speaker go-librespot[24034]: time="2026-09-01T01:26:27+02:00" level=info msg="running go-librespot 0.4.0"
Sep 01 01:26:27 stefans-speaker go-librespot[24034]: time="2026-09-01T01:26:27+02:00" level=debug msg="app state loaded"
Sep 01 01:26:27 stefans-speaker go-librespot[24034]: time="2026-09-01T01:26:27+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Sep 01 01:26:27 stefans-speaker go-librespot[24034]: time="2026-09-01T01:26:27+02: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]"
Sep 01 01:26:27 stefans-speaker go-librespot[24034]: time="2026-09-01T01:26:27+02: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]"
Sep 01 01:26:27 stefans-speaker go-librespot[24034]: time="2026-09-01T01:26:27+02: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]"
Sep 01 01:26:27 stefans-speaker go-librespot[24034]: time="2026-09-01T01:26:27+02:00" level=info msg="zeroconf server listening on port 36047"
Sep 01 01:26:27 stefans-speaker go-librespot[24034]: time="2026-09-01T01:26:27+02:00" level=debug msg="obtained new client token: AAGNeaeqlcClhh6cO16SOUKA6hgdLoAG+bdhX+70LpD8+D/Ur3oB9KR7tGWrRj49DHBtdQUc83ANrj92IZA1TVr0p238fef/sIOeCMZkeHICrlkTfbOlSF6TUkt75tmCfxrGlsxy25LBcw8hinWnldhRiPr6laye4loLHIqMeqyMzMgfdET5V4S6HK3VTfSg/0LpJS6wUGhcvoPkLP01ibfbq6fDsDqHRhvYUYsmyny6319M/5uSnfuoCFM="
Sep 01 01:26:27 stefans-speaker go-librespot[24034]: time="2026-09-01T01:26:27+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused"
Sep 01 01:26:27 stefans-speaker go-librespot[24034]: time="2026-09-01T01:26:27+02:00" level=debug msg="connected to ap-gew4.spotify.com:443"
Sep 01 01:26:27 stefans-speaker go-librespot[24034]: time="2026-09-01T01:26:27+02:00" level=debug msg="completed keyexchange"
Sep 01 01:26:27 stefans-speaker go-librespot[24034]: time="2026-09-01T01:26:27+02:00" level=debug msg="completed challenge"
Sep 01 01:26:27 stefans-speaker go-librespot[24034]: time="2026-09-01T01:26:27+02:00" level=info msg="authenticated AP" username="31************************cy"
Sep 01 01:26:27 stefans-speaker volumio-remote-updater[679]: [2026-09-01 01:26:27] [connect] Successful connection
Sep 01 01:26:27 stefans-speaker volumio-remote-updater[679]: [2026-09-01 01:26:27] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788218787 101
Sep 01 01:26:27 stefans-speaker volumio[23743]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 2
Sep 01 01:26:27 stefans-speaker go-librespot[24034]: time="2026-09-01T01:26:27+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Sep 01 01:26:27 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Sep 01 01:26:27 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Sep 01 01:26:29 stefans-speaker sudo[24044]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:26:29 stefans-speaker sudo[24044]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Sep 01 01:26:29 stefans-speaker sudo[24044]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:26:29 stefans-speaker sudo[24046]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:26:29 stefans-speaker sudo[24046]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Sep 01 01:26:29 stefans-speaker sudo[24046]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:26:29 stefans-speaker systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Sep 01 01:26:29 stefans-speaker systemd[1]: mpd_monitor.service: Deactivated successfully.
Sep 01 01:26:29 stefans-speaker systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Sep 01 01:26:29 stefans-speaker systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Sep 01 01:26:29 stefans-speaker sudo[24044]: pam_unix(sudo:session): session closed for user root
Sep 01 01:26:29 stefans-speaker mpd_monitor.sh[24049]: MPD Monitor Service: Starting MPD Monitor Service
Sep 01 01:26:29 stefans-speaker volumio[23743]: info: Successfully started MPD Monitor
Sep 01 01:26:29 stefans-speaker sudo[24046]: pam_unix(sudo:session): session closed for user root
Sep 01 01:26:29 stefans-speaker volumio[23743]: info: Successfully started MPD Monitor
Sep 01 01:26:30 stefans-speaker volumio[23743]: info: Initializing connection to go-librespot Websocket
Sep 01 01:26:30 stefans-speaker volumio[23743]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Sep 01 01:26:31 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Sep 01 01:26:31 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:31 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:31 stefans-speaker go-librespot[24053]: go-librespot daemon starting...
Sep 01 01:26:31 stefans-speaker go-librespot[24054]: time="2026-09-01T01:26:31+02:00" level=info msg="running go-librespot 0.4.0"
Sep 01 01:26:31 stefans-speaker go-librespot[24054]: time="2026-09-01T01:26:31+02:00" level=debug msg="app state loaded"
Sep 01 01:26:31 stefans-speaker go-librespot[24054]: time="2026-09-01T01:26:31+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Sep 01 01:26:31 stefans-speaker volumio[23743]: error: Failed LSINFO: Error:  [50@0] {lsinfo} No such directory
Sep 01 01:26:31 stefans-speaker go-librespot[24054]: time="2026-09-01T01:26:31+02: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]"
Sep 01 01:26:31 stefans-speaker go-librespot[24054]: time="2026-09-01T01:26:31+02: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]"
Sep 01 01:26:31 stefans-speaker go-librespot[24054]: time="2026-09-01T01:26:31+02: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]"
Sep 01 01:26:31 stefans-speaker go-librespot[24054]: time="2026-09-01T01:26:31+02:00" level=info msg="zeroconf server listening on port 37013"
Sep 01 01:26:31 stefans-speaker go-librespot[24054]: time="2026-09-01T01:26:31+02:00" level=debug msg="obtained new client token: AAFtTIyHwCpwtXgYKc9r5h2+lksvboBFkCCSc/4SYvintMqY0hshhJbZxAv5ZUB3g/xLOqObmkhusExOKlYT69CUgGMvhjf4WG/PvphBo5xBel4w3ZsDRzXgSFe4lfMJfUfMPOwAfrgHIkIwS4vA5jRmEGQjyhBiYJIUdpw1YN0ky7OFimRTLiQRbtttzUBy0VlLpX3P5c39loli6yU6kHlex/jixhqrfCkhu2Ogt75pVl9nm7OWvadPTns="
Sep 01 01:26:31 stefans-speaker go-librespot[24054]: time="2026-09-01T01:26:31+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Sep 01 01:26:31 stefans-speaker go-librespot[24054]: time="2026-09-01T01:26:31+02:00" level=debug msg="completed keyexchange"
Sep 01 01:26:31 stefans-speaker go-librespot[24054]: time="2026-09-01T01:26:31+02:00" level=debug msg="completed challenge"
Sep 01 01:26:31 stefans-speaker go-librespot[24054]: time="2026-09-01T01:26:31+02:00" level=info msg="authenticated AP" username="31************************cy"
Sep 01 01:26:31 stefans-speaker go-librespot[24054]: time="2026-09-01T01:26:31+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Sep 01 01:26:31 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Sep 01 01:26:31 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Sep 01 01:26:33 stefans-speaker volumio[23743]: info: Initializing connection to go-librespot Websocket
Sep 01 01:26:33 stefans-speaker volumio[23743]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: Adding plugin bluetooth to MyMusic Plugins
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: Adding plugin multiroom to MyMusic Plugins
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: Adding plugin metavolumio to MyMusic Plugins
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: Adding plugin cd_controller to MyMusic Plugins
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: Adding plugin qobuzconnect to MyMusic Plugins
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: Adding plugin smart_inputs to MyMusic Plugins
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: Adding plugin tidalconnect to MyMusic Plugins
Sep 01 01:26:34 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Sep 01 01:26:35 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Sep 01 01:26:35 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:35 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:35 stefans-speaker go-librespot[24076]: go-librespot daemon starting...
Sep 01 01:26:35 stefans-speaker go-librespot[24077]: time="2026-09-01T01:26:35+02:00" level=info msg="running go-librespot 0.4.0"
Sep 01 01:26:35 stefans-speaker go-librespot[24077]: time="2026-09-01T01:26:35+02:00" level=debug msg="app state loaded"
Sep 01 01:26:35 stefans-speaker go-librespot[24077]: time="2026-09-01T01:26:35+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Sep 01 01:26:35 stefans-speaker go-librespot[24077]: time="2026-09-01T01:26:35+02: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]"
Sep 01 01:26:35 stefans-speaker go-librespot[24077]: time="2026-09-01T01:26:35+02: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]"
Sep 01 01:26:35 stefans-speaker go-librespot[24077]: time="2026-09-01T01:26:35+02: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]"
Sep 01 01:26:35 stefans-speaker go-librespot[24077]: time="2026-09-01T01:26:35+02:00" level=info msg="zeroconf server listening on port 42721"
Sep 01 01:26:35 stefans-speaker go-librespot[24077]: time="2026-09-01T01:26:35+02:00" level=debug msg="obtained new client token: AAHpRg7pSsAox+mlZ1hnhb0UXKINXT5ARLnJkSfYENaeJYlGxviSEKKd5N1xu1XneXEPN0cUSs9PcUrzy7MDq7OMx2wZyvy+cDhrWWEX8F+wfPHe+5CIju41e7/X6cH15P5IiMR58n/aerbVY/z/PizinswH/3tgtNyCk9XFzLPyqiJrSYWdNnxkTJCL9x8Kz3BJKauRMIg9Og7ZhAe7IP0bV/ZFVQPFV8Jyot0933JzUMZPMwJZ7YpgKN4="
Sep 01 01:26:35 stefans-speaker go-librespot[24077]: time="2026-09-01T01:26:35+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused"
Sep 01 01:26:35 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Sep 01 01:26:35 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Sep 01 01:26:35 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:35 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:35 stefans-speaker volumio[23743]: info: Starting MyVolumio Remote Streaming Endpoints
Sep 01 01:26:35 stefans-speaker go-librespot[24077]: time="2026-09-01T01:26:35+02:00" level=debug msg="connected to ap-gew4.spotify.com:443"
Sep 01 01:26:35 stefans-speaker volumio[23743]: info: MyVolumio login type: Token
Sep 01 01:26:35 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Sep 01 01:26:35 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Sep 01 01:26:35 stefans-speaker go-librespot[24077]: time="2026-09-01T01:26:35+02:00" level=debug msg="completed keyexchange"
Sep 01 01:26:35 stefans-speaker go-librespot[24077]: time="2026-09-01T01:26:35+02:00" level=debug msg="completed challenge"
Sep 01 01:26:35 stefans-speaker go-librespot[24077]: time="2026-09-01T01:26:35+02:00" level=info msg="authenticated AP" username="31************************cy"
Sep 01 01:26:35 stefans-speaker go-librespot[24077]: time="2026-09-01T01:26:35+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Sep 01 01:26:35 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Sep 01 01:26:35 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Sep 01 01:26:36 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Sep 01 01:26:36 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Sep 01 01:26:36 stefans-speaker volumio[23743]: info: Streaming services startup
Sep 01 01:26:36 stefans-speaker volumio[23743]: info: Starting Streaming Daemon
Sep 01 01:26:36 stefans-speaker volumio[23743]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Sep 01 01:26:36 stefans-speaker sudo[24086]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:26:36 stefans-speaker sudo[24086]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Sep 01 01:26:36 stefans-speaker sudo[24086]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:26:36 stefans-speaker sudo[24086]: pam_unix(sudo:session): session closed for user root
Sep 01 01:26:36 stefans-speaker volumio[23743]: info: Initializing connection to go-librespot Websocket
Sep 01 01:26:36 stefans-speaker volumio[23743]: error: Cannot start Volumio Streaming Daemon
Sep 01 01:26:36 stefans-speaker volumio[23743]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Sep 01 01:26:36 stefans-speaker volumio[23743]: sudo: unable to resolve host stefans-speaker: System error
Sep 01 01:26:36 stefans-speaker volumio[23743]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Sep 01 01:26:36 stefans-speaker volumio[23743]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Sep 01 01:26:37 stefans-speaker volumio[23743]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Sep 01 01:26:37 stefans-speaker volumio[23743]: info: MyVolumio token set successfully
Sep 01 01:26:37 stefans-speaker volumio[23743]: info: MYVOLUMIO: Adding device
Sep 01 01:26:37 stefans-speaker volumio[23743]: info: MYVOLUMIO: Evaluating Server
Sep 01 01:26:38 stefans-speaker volumio[23743]: info: MyVolumio status changed
Sep 01 01:26:38 stefans-speaker volumio[23743]: info: Streaming services startup
Sep 01 01:26:38 stefans-speaker volumio[23743]: info: Starting Streaming Daemon
Sep 01 01:26:38 stefans-speaker volumio[23743]: info: Removing browser output: myVolumio user plan is not superstar
Sep 01 01:26:38 stefans-speaker volumio[23743]: info: Removing audio output:
Sep 01 01:26:38 stefans-speaker volumio[23743]: info: Stoppping Tunnel 1
Sep 01 01:26:38 stefans-speaker sudo[24114]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:26:38 stefans-speaker sudo[24116]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:26:38 stefans-speaker sudo[24114]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Sep 01 01:26:38 stefans-speaker sudo[24114]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:26:38 stefans-speaker sudo[24116]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service
Sep 01 01:26:38 stefans-speaker sudo[24116]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:26:38 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 01 01:26:38 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 01 01:26:38 stefans-speaker sudo[24114]: pam_unix(sudo:session): session closed for user root
Sep 01 01:26:38 stefans-speaker volumio[23743]: error: Cannot start Volumio Streaming Daemon
Sep 01 01:26:38 stefans-speaker volumio[23743]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Sep 01 01:26:38 stefans-speaker volumio[23743]: sudo: unable to resolve host stefans-speaker: System error
Sep 01 01:26:38 stefans-speaker volumio[23743]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Sep 01 01:26:38 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 01 01:26:38 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 01 01:26:38 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 01 01:26:38 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 01 01:26:38 stefans-speaker sudo[24116]: pam_unix(sudo:session): session closed for user root
Sep 01 01:26:38 stefans-speaker volumio[23743]: info: Remote SSH Stopped
Sep 01 01:26:39 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Sep 01 01:26:39 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:39 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:39 stefans-speaker go-librespot[24119]: go-librespot daemon starting...
Sep 01 01:26:39 stefans-speaker go-librespot[24120]: time="2026-09-01T01:26:39+02:00" level=info msg="running go-librespot 0.4.0"
Sep 01 01:26:39 stefans-speaker go-librespot[24120]: time="2026-09-01T01:26:39+02:00" level=debug msg="app state loaded"
Sep 01 01:26:39 stefans-speaker go-librespot[24120]: time="2026-09-01T01:26:39+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Sep 01 01:26:39 stefans-speaker go-librespot[24120]: time="2026-09-01T01:26:39+02: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]"
Sep 01 01:26:39 stefans-speaker go-librespot[24120]: time="2026-09-01T01:26:39+02: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]"
Sep 01 01:26:39 stefans-speaker go-librespot[24120]: time="2026-09-01T01:26:39+02: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]"
Sep 01 01:26:39 stefans-speaker go-librespot[24120]: time="2026-09-01T01:26:39+02:00" level=info msg="zeroconf server listening on port 33549"
Sep 01 01:26:39 stefans-speaker go-librespot[24120]: time="2026-09-01T01:26:39+02:00" level=debug msg="obtained new client token: AAE7sqQSbTAEY40AszEo668RL3GM+czoWOrHvEY/JMRzt8bSjWn00KoJqufikpR173FdjbcELJI/qUEi8orPCZSF5gU0QWbKZcmaJjzJcROLqrRQbs9MMDDWgVY0USQb9XTn3WWAMtgleIpXbni6SZHCDypNDzqhY4y+9465liEr5VyuFZfHubAy/DGWaMoq1BeVy5nWEC+hYkKs1NLv8Vj/Lio/hZZ8p9XBCPz3FlnHSCkDz/N8rBumRC8="
Sep 01 01:26:39 stefans-speaker go-librespot[24120]: time="2026-09-01T01:26:39+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Sep 01 01:26:39 stefans-speaker go-librespot[24120]: time="2026-09-01T01:26:39+02:00" level=debug msg="completed keyexchange"
Sep 01 01:26:39 stefans-speaker go-librespot[24120]: time="2026-09-01T01:26:39+02:00" level=debug msg="completed challenge"
Sep 01 01:26:39 stefans-speaker go-librespot[24120]: time="2026-09-01T01:26:39+02:00" level=info msg="authenticated AP" username="31************************cy"
Sep 01 01:26:39 stefans-speaker go-librespot[24120]: time="2026-09-01T01:26:39+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Sep 01 01:26:39 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Sep 01 01:26:39 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Sep 01 01:26:39 stefans-speaker volumio[23743]: info: Initializing connection to go-librespot Websocket
Sep 01 01:26:39 stefans-speaker volumio[23743]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Sep 01 01:26:40 stefans-speaker volumio[23743]: info: Setting Geolocation for MyVolumio to eu2
Sep 01 01:26:40 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:40 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:40 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:40 stefans-speaker volumio[23743]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Sep 01 01:26:41 stefans-speaker volumio[23743]: info: Updating MyVolumio device info
Sep 01 01:26:41 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:41 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:41 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:41 stefans-speaker volumio[23743]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Sep 01 01:26:42 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Sep 01 01:26:42 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:42 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:42 stefans-speaker go-librespot[24127]: go-librespot daemon starting...
Sep 01 01:26:42 stefans-speaker volumio[23743]: info: Initializing connection to go-librespot Websocket
Sep 01 01:26:42 stefans-speaker volumio[23743]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Sep 01 01:26:42 stefans-speaker go-librespot[24128]: time="2026-09-01T01:26:42+02:00" level=info msg="running go-librespot 0.4.0"
Sep 01 01:26:42 stefans-speaker go-librespot[24128]: time="2026-09-01T01:26:42+02:00" level=debug msg="app state loaded"
Sep 01 01:26:42 stefans-speaker go-librespot[24128]: time="2026-09-01T01:26:42+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Sep 01 01:26:43 stefans-speaker go-librespot[24128]: time="2026-09-01T01:26:43+02: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]"
Sep 01 01:26:43 stefans-speaker go-librespot[24128]: time="2026-09-01T01:26:43+02: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]"
Sep 01 01:26:43 stefans-speaker go-librespot[24128]: time="2026-09-01T01:26:43+02: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]"
Sep 01 01:26:43 stefans-speaker go-librespot[24128]: time="2026-09-01T01:26:43+02:00" level=info msg="zeroconf server listening on port 38335"
Sep 01 01:26:43 stefans-speaker go-librespot[24128]: time="2026-09-01T01:26:43+02:00" level=debug msg="obtained new client token: AAFq25Jm5102Kei6bSampw42ABW+mC6IhTpnsaE3wNFNX5sTA0DR8hk4kFYiT+2ncFboqhyXTJSHdQ2sHfSLLL3fOCQcLwvaa+kl4NE7bFtXtfAhgFNDpXLl6/z8XBs8TCv6hWotRFccUzm1FIBpVpUScQRBpuYejqrNALiY7Y1WMjTGkiZIlnQc3AeWZ67yv7+plPF8ZIncCr5hdg88QsCdPRNPswlHcFD6SBw1fBClVdNAcYTL2UVq"
Sep 01 01:26:43 stefans-speaker go-librespot[24128]: time="2026-09-01T01:26:43+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Sep 01 01:26:43 stefans-speaker go-librespot[24128]: time="2026-09-01T01:26:43+02:00" level=debug msg="completed keyexchange"
Sep 01 01:26:43 stefans-speaker go-librespot[24128]: time="2026-09-01T01:26:43+02:00" level=debug msg="completed challenge"
Sep 01 01:26:43 stefans-speaker go-librespot[24128]: time="2026-09-01T01:26:43+02:00" level=info msg="authenticated AP" username="31************************cy"
Sep 01 01:26:43 stefans-speaker go-librespot[24128]: time="2026-09-01T01:26:43+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Sep 01 01:26:43 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Sep 01 01:26:43 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Sep 01 01:26:44 stefans-speaker volumio[23743]: info: MYVOLUMIO: Adding device
Sep 01 01:26:44 stefans-speaker volumio[23743]: info: MYVOLUMIO: Evaluating Server
Sep 01 01:26:45 stefans-speaker volumio[23743]: info: Initializing connection to go-librespot Websocket
Sep 01 01:26:45 stefans-speaker volumio[23743]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Sep 01 01:26:46 stefans-speaker volumio[23743]: info: Setting Geolocation for MyVolumio to eu2
Sep 01 01:26:46 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:46 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:46 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:46 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6.
Sep 01 01:26:46 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:46 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:46 stefans-speaker go-librespot[24168]: go-librespot daemon starting...
Sep 01 01:26:46 stefans-speaker go-librespot[24169]: time="2026-09-01T01:26:46+02:00" level=info msg="running go-librespot 0.4.0"
Sep 01 01:26:46 stefans-speaker go-librespot[24169]: time="2026-09-01T01:26:46+02:00" level=debug msg="app state loaded"
Sep 01 01:26:46 stefans-speaker go-librespot[24169]: time="2026-09-01T01:26:46+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Sep 01 01:26:46 stefans-speaker go-librespot[24169]: time="2026-09-01T01:26:46+02: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]"
Sep 01 01:26:46 stefans-speaker go-librespot[24169]: time="2026-09-01T01:26:46+02: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]"
Sep 01 01:26:46 stefans-speaker go-librespot[24169]: time="2026-09-01T01:26:46+02: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]"
Sep 01 01:26:46 stefans-speaker volumio[23743]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Sep 01 01:26:46 stefans-speaker go-librespot[24169]: time="2026-09-01T01:26:46+02:00" level=info msg="zeroconf server listening on port 36425"
Sep 01 01:26:46 stefans-speaker go-librespot[24169]: time="2026-09-01T01:26:46+02:00" level=debug msg="obtained new client token: AAEl6e2NIud7KyNDeKq/LkOM4UJ93OivUYwNofsMXk+KrS4M23nkTbsz4gT5V75yI2bEtOTCJYs66F97wnZ+jOiVi4Tg+LtoqeklczIdUARbWzJRekRCNfxD67MDj3tlbIkVSth6TpcrgfYT2VpIs9a1kOQewWDageKuKwha/Zwic5pQm8GWBhS91wnozGe4PqXqAG8KmHFmEVmht82KHV0iMTKPFh/bP61WF+21lZApp4tw831gaCSHo6A="
Sep 01 01:26:47 stefans-speaker go-librespot[24169]: time="2026-09-01T01:26:47+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused"
Sep 01 01:26:47 stefans-speaker go-librespot[24169]: time="2026-09-01T01:26:47+02:00" level=debug msg="connected to ap-gew4.spotify.com:443"
Sep 01 01:26:47 stefans-speaker go-librespot[24169]: time="2026-09-01T01:26:47+02:00" level=debug msg="completed keyexchange"
Sep 01 01:26:47 stefans-speaker go-librespot[24169]: time="2026-09-01T01:26:47+02:00" level=debug msg="completed challenge"
Sep 01 01:26:47 stefans-speaker go-librespot[24169]: time="2026-09-01T01:26:47+02:00" level=info msg="authenticated AP" username="31************************cy"
Sep 01 01:26:47 stefans-speaker go-librespot[24169]: time="2026-09-01T01:26:47+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Sep 01 01:26:47 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Sep 01 01:26:47 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Sep 01 01:26:47 stefans-speaker volumio[23743]: info: Updating MyVolumio device info
Sep 01 01:26:47 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:47 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:47 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:47 stefans-speaker volumio[23743]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Sep 01 01:26:48 stefans-speaker volumio[23743]: info: Initializing connection to go-librespot Websocket
Sep 01 01:26:48 stefans-speaker volumio[23743]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Sep 01 01:26:50 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Sep 01 01:26:50 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:50 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:50 stefans-speaker go-librespot[24179]: go-librespot daemon starting...
Sep 01 01:26:50 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Sep 01 01:26:50 stefans-speaker go-librespot[24180]: time="2026-09-01T01:26:50+02:00" level=info msg="running go-librespot 0.4.0"
Sep 01 01:26:50 stefans-speaker go-librespot[24180]: time="2026-09-01T01:26:50+02:00" level=debug msg="app state loaded"
Sep 01 01:26:50 stefans-speaker go-librespot[24180]: time="2026-09-01T01:26:50+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Sep 01 01:26:50 stefans-speaker volumio[23743]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3
Sep 01 01:26:50 stefans-speaker volumio[23743]: info: CoreCommandRouter::volumioGetState
Sep 01 01:26:50 stefans-speaker volumio[23743]: info: CorePlayQueue::getTrack 0
Sep 01 01:26:50 stefans-speaker go-librespot[24180]: time="2026-09-01T01:26:50+02: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]"
Sep 01 01:26:50 stefans-speaker go-librespot[24180]: time="2026-09-01T01:26:50+02: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]"
Sep 01 01:26:50 stefans-speaker go-librespot[24180]: time="2026-09-01T01:26:50+02: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]"
Sep 01 01:26:50 stefans-speaker go-librespot[24180]: time="2026-09-01T01:26:50+02:00" level=info msg="zeroconf server listening on port 38273"
Sep 01 01:26:50 stefans-speaker go-librespot[24180]: time="2026-09-01T01:26:50+02:00" level=debug msg="obtained new client token: AAGy7T9B7hzagZn7Ux+6H0+xS7jwp23F793jcyTiKbrtG0EYlNOBffr1uT4Sqa3vNxriraN0GwWck0ZlzkQrG7q+xLz+dbF0W0IhedYRokhXbLoQM756kEtWqfHeW9oYCxkl82owFWoyYp7uXZzwQPW8Xr9LqGquw7/gXt7f9Niniz/TY9EYdv3R6M9DiUSVlm5BDAqPGQeCj+jJ0GlO4b3UxmroOEEnfK+25q9Fwl85mIXTBgUw2A92xm4="
Sep 01 01:26:51 stefans-speaker go-librespot[24180]: time="2026-09-01T01:26:51+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Sep 01 01:26:51 stefans-speaker go-librespot[24180]: time="2026-09-01T01:26:51+02:00" level=debug msg="completed keyexchange"
Sep 01 01:26:51 stefans-speaker go-librespot[24180]: time="2026-09-01T01:26:51+02:00" level=debug msg="completed challenge"
Sep 01 01:26:51 stefans-speaker go-librespot[24180]: time="2026-09-01T01:26:51+02:00" level=info msg="authenticated AP" username="31************************cy"
Sep 01 01:26:51 stefans-speaker go-librespot[24180]: time="2026-09-01T01:26:51+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Sep 01 01:26:51 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Sep 01 01:26:51 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Sep 01 01:26:51 stefans-speaker volumio[23743]: info: Initializing connection to go-librespot Websocket
Sep 01 01:26:51 stefans-speaker volumio[23743]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Sep 01 01:26:52 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Sep 01 01:26:52 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:52 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Sep 01 01:26:52 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Sep 01 01:26:52 stefans-speaker volumio-remote-updater[679]: Test mode disabled
Sep 01 01:26:52 stefans-speaker volumio-remote-updater[679]: Alpha mode disabled
Sep 01 01:26:52 stefans-speaker volumio-remote-updater[679]: Alpha legacy test mode disabled
Sep 01 01:26:52 stefans-speaker volumio[23743]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
Fix for missing PWM backlight module
Fix for crash loop on Onboarding plugin
NEW ADDITIONS
Bump RPi/CM4 kernel to 6.12.74
","title":"Update v4.119","updateavailable":true}
Sep 01 01:26:52 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Sep 01 01:26:54 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8.
Sep 01 01:26:54 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:54 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:54 stefans-speaker go-librespot[24192]: go-librespot daemon starting...
Sep 01 01:26:54 stefans-speaker go-librespot[24193]: time="2026-09-01T01:26:54+02:00" level=info msg="running go-librespot 0.4.0"
Sep 01 01:26:54 stefans-speaker go-librespot[24193]: time="2026-09-01T01:26:54+02:00" level=debug msg="app state loaded"
Sep 01 01:26:54 stefans-speaker go-librespot[24193]: time="2026-09-01T01:26:54+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Sep 01 01:26:54 stefans-speaker go-librespot[24193]: time="2026-09-01T01:26:54+02: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]"
Sep 01 01:26:54 stefans-speaker go-librespot[24193]: time="2026-09-01T01:26:54+02: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]"
Sep 01 01:26:54 stefans-speaker go-librespot[24193]: time="2026-09-01T01:26:54+02: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]"
Sep 01 01:26:54 stefans-speaker go-librespot[24193]: time="2026-09-01T01:26:54+02:00" level=info msg="zeroconf server listening on port 34877"
Sep 01 01:26:54 stefans-speaker volumio[23743]: info: Initializing connection to go-librespot Websocket
Sep 01 01:26:54 stefans-speaker go-librespot[24193]: time="2026-09-01T01:26:54+02:00" level=debug msg="new websocket client"
Sep 01 01:26:54 stefans-speaker volumio[23743]: info: Connection to go-librespot Websocket established
Sep 01 01:26:54 stefans-speaker go-librespot[24193]: time="2026-09-01T01:26:54+02:00" level=debug msg="obtained new client token: AAEFz704rOVfdReOKEJlR5nUBV5v+g1AUsMu4IvBr7xHKmw7hsyS5buU4pBrKYmeds2CEjotp7Iee5DuzKe0xIIdbtbAmLLE704v8f/CJrLNzVyK+jinXWjNBW3Tu0bUGaQEt2fNAH/2GLffvazqIHbe1moGqchq6nvK6VflNXvPRwO9oPYNOGKmlQ6KWg4UhnOBH8ndwVR9WrvrDxKYAlW8hV63tdh2jA7ocjIKdliuPgY15s/hZicCNoc="
Sep 01 01:26:55 stefans-speaker go-librespot[24193]: time="2026-09-01T01:26:55+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Sep 01 01:26:55 stefans-speaker go-librespot[24193]: time="2026-09-01T01:26:55+02:00" level=debug msg="completed keyexchange"
Sep 01 01:26:55 stefans-speaker go-librespot[24193]: time="2026-09-01T01:26:55+02:00" level=debug msg="completed challenge"
Sep 01 01:26:55 stefans-speaker go-librespot[24193]: time="2026-09-01T01:26:55+02:00" level=info msg="authenticated AP" username="31************************cy"
Sep 01 01:26:55 stefans-speaker go-librespot[24193]: time="2026-09-01T01:26:55+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Sep 01 01:26:55 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Sep 01 01:26:55 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Sep 01 01:26:55 stefans-speaker volumio[23743]: info: Connection to go-librespot Websocket closed
Sep 01 01:26:55 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:55 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:55 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
Sep 01 01:26:55 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Sep 01 01:26:55 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Sep 01 01:26:55 stefans-speaker volumio[23743]: info: CoreCommandRouter::volumioGetBrowseSources
Sep 01 01:26:55 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Sep 01 01:26:56 stefans-speaker volumio[23743]: error: MyVolumio Plugin failed to authenticate in a timely fashion
Sep 01 01:26:56 stefans-speaker volumio[23743]: info: Completed starting MyVolumio Plugin
Sep 01 01:26:56 stefans-speaker volumio[23743]:  [Metrics]  CommandRouter:  44s 221.69ms 
Sep 01 01:26:56 stefans-speaker volumio[23743]: info: CoreCommandRouter::volumiosetStartupVolume
Sep 01 01:26:56 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:26:56 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:26:56 stefans-speaker volumio[23743]: info: CoreCommandRouter::Close All Modals sent
Sep 01 01:26:56 stefans-speaker volumio[23743]: info: CoreCommandRouter::Close All Modals sent
Sep 01 01:26:57 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
Sep 01 01:26:57 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Sep 01 01:26:57 stefans-speaker volumio[23743]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
Sep 01 01:26:57 stefans-speaker volumio[23743]: info: Getting Spotify volume
Sep 01 01:26:57 stefans-speaker volumio[23743]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Sep 01 01:26:57 stefans-speaker volumio[23743]: Error: connect ECONNREFUSED 127.0.0.1:9879
Sep 01 01:26:57 stefans-speaker volumio[23743]:     at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Sep 01 01:26:57 stefans-speaker volumio[23743]:   errno: -111,
Sep 01 01:26:57 stefans-speaker volumio[23743]:   code: 'ECONNREFUSED',
Sep 01 01:26:57 stefans-speaker volumio[23743]:   syscall: 'connect',
Sep 01 01:26:57 stefans-speaker volumio[23743]:   address: '127.0.0.1',
Sep 01 01:26:57 stefans-speaker volumio[23743]:   port: 9879,
Sep 01 01:26:57 stefans-speaker volumio[23743]:   response: undefined
Sep 01 01:26:57 stefans-speaker volumio[23743]: }
Sep 01 01:26:57 stefans-speaker volumio[23743]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Sep 01 01:26:58 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9.
Sep 01 01:26:58 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:58 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:26:58 stefans-speaker go-librespot[24232]: go-librespot daemon starting...
Sep 01 01:26:58 stefans-speaker go-librespot[24233]: time="2026-09-01T01:26:58+02:00" level=info msg="running go-librespot 0.4.0"
Sep 01 01:26:58 stefans-speaker go-librespot[24233]: time="2026-09-01T01:26:58+02:00" level=debug msg="app state loaded"
Sep 01 01:26:58 stefans-speaker go-librespot[24233]: time="2026-09-01T01:26:58+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Sep 01 01:26:58 stefans-speaker go-librespot[24233]: time="2026-09-01T01:26:58+02: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]"
Sep 01 01:26:58 stefans-speaker go-librespot[24233]: time="2026-09-01T01:26:58+02: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]"
Sep 01 01:26:58 stefans-speaker go-librespot[24233]: time="2026-09-01T01:26:58+02: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]"
Sep 01 01:26:58 stefans-speaker go-librespot[24233]: time="2026-09-01T01:26:58+02:00" level=info msg="zeroconf server listening on port 41137"
Sep 01 01:26:58 stefans-speaker sudo[24243]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:26:58 stefans-speaker sudo[24243]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-09-01 01:25'
Sep 01 01:26:58 stefans-speaker sudo[24243]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:26:58 stefans-speaker go-librespot[24233]: time="2026-09-01T01:26:58+02:00" level=debug msg="obtained new client token: AAEG4eqZbZ1z2rk1bdvUuAXhz3tvdqq6hBFlPIk7ziKTx7M7XZt4Ek/6+h1SKHIHPczSuAagesiL9Mc10FgnOvyVbuYFb9IoeGNmDC3avf582gSZdR5a8gOZ5XDHLShhpznbQqEOBjc2iGCo8ZLQjBgwWE9ukuKZqWJc48AZvq+gVXbvzii0oE3EQcRN1grU4QQQjZeVqqIRYZEfJHMY4145h04uULPy+eg8mY+PMbzCkHIk7bseLcEg29Y="
Sep 01 01:26:58 stefans-speaker go-librespot[24233]: time="2026-09-01T01:26:58+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Sep 01 01:26:58 stefans-speaker go-librespot[24233]: time="2026-09-01T01:26:58+02:00" level=debug msg="completed keyexchange"
Sep 01 01:26:58 stefans-speaker go-librespot[24233]: time="2026-09-01T01:26:58+02:00" level=debug msg="completed challenge"
Sep 01 01:26:58 stefans-speaker go-librespot[24233]: time="2026-09-01T01:26:58+02:00" level=info msg="authenticated AP" username="31************************cy"
Sep 01 01:26:59 stefans-speaker sudo[24243]: pam_unix(sudo:session): session closed for user root
Sep 01 01:26:59 stefans-speaker volumio[23743]: sudo: unable to resolve host stefans-speaker: System error
Sep 01 01:26:59 stefans-speaker go-librespot[24233]: time="2026-09-01T01:26:59+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Sep 01 01:26:59 stefans-speaker volumio-remote-updater[679]: [2026-09-01 01:26:59] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Sep 01 01:26:59 stefans-speaker volumio-remote-updater[679]: [2026-09-01 01:26:59] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Sep 01 01:26:59 stefans-speaker systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Sep 01 01:26:59 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Sep 01 01:26:59 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Sep 01 01:26:59 stefans-speaker kernel: bcm2835-audio bcm2835-audio: failed to close VCHI service connection (status=-11)
Sep 01 01:26:59 stefans-speaker systemd[1]: volumio.service: Failed with result 'exit-code'.
Sep 01 01:26:59 stefans-speaker systemd[1]: volumio.service: Consumed 35.401s CPU time.
Sep 01 01:26:59 stefans-speaker systemd[1]: Started dynamicswap.service - dynamicswap service.
Sep 01 01:26:59 stefans-speaker systemd[1]: dynamicswap.service: Deactivated successfully.
Sep 01 01:26:59 stefans-speaker systemd[1]: volumio.service: Scheduled restart job, restart counter is at 325.
Sep 01 01:26:59 stefans-speaker systemd[1]: Started dynamicswap.service - dynamicswap service.
Sep 01 01:26:59 stefans-speaker systemd[1]: Stopped volumio.service - Volumio Backend Module.
Sep 01 01:26:59 stefans-speaker systemd[1]: volumio.service: Consumed 35.401s CPU time.
Sep 01 01:26:59 stefans-speaker systemd[1]: Started volumio.service - Volumio Backend Module.
Sep 01 01:26:59 stefans-speaker systemd[1]: dynamicswap.service: Deactivated successfully.
Sep 01 01:27:01 stefans-speaker volumio[24258]: info: -------------------------------------------
Sep 01 01:27:01 stefans-speaker volumio[24258]: info: -----            Volumio3              ----
Sep 01 01:27:01 stefans-speaker volumio[24258]: info: -------------------------------------------
Sep 01 01:27:01 stefans-speaker volumio[24258]: info: -----          System startup          ----
Sep 01 01:27:01 stefans-speaker volumio[24258]: info: -------------------------------------------
Sep 01 01:27:02 stefans-speaker volumio[24258]: info: MYVOLUMIO Environment detected
Sep 01 01:27:02 stefans-speaker volumio[24258]: info: Plugin folders cleanup
Sep 01 01:27:02 stefans-speaker volumio[24258]: info: Scanning into folder /volumio/app/plugins/
Sep 01 01:27:02 stefans-speaker volumio[24258]: info: Scanning category audio_interface
Sep 01 01:27:02 stefans-speaker volumio[24258]: info: Scanning category miscellanea
Sep 01 01:27:02 stefans-speaker volumio[24258]: info: Scanning category music_service
Sep 01 01:27:02 stefans-speaker volumio[24258]: info: Scanning category plugins.json
Sep 01 01:27:02 stefans-speaker volumio[24258]: info: Scanning category system_controller
Sep 01 01:27:02 stefans-speaker volumio[24258]: info: Scanning category user_interface
Sep 01 01:27:02 stefans-speaker volumio[24258]: info: Scanning into folder /data/plugins/
Sep 01 01:27:02 stefans-speaker volumio[24258]: info: Scanning category music_service
Sep 01 01:27:02 stefans-speaker volumio[24258]: info: Plugin folders cleanup completed
Sep 01 01:27:02 stefans-speaker volumio[24258]: info: -------------------------------------------
Sep 01 01:27:02 stefans-speaker volumio[24258]: info: -----      Core plugins startup        ----
Sep 01 01:27:02 stefans-speaker volumio[24258]: info: -------------------------------------------
Sep 01 01:27:02 stefans-speaker volumio[24258]: info: Loading plugins from folder /volumio/app/plugins/
Sep 01 01:27:02 stefans-speaker volumio[24258]: info: Adding plugin upnp to MyMusic Plugins
Sep 01 01:27:02 stefans-speaker volumio[24258]: info: Adding plugin airplay_emulation to MyMusic Plugins
Sep 01 01:27:02 stefans-speaker volumio[24258]: info: Adding plugin upnp_browser to MyMusic Plugins
Sep 01 01:27:02 stefans-speaker volumio[24258]: info: Loading plugins from folder /data/plugins/
Sep 01 01:27:02 stefans-speaker volumio[24258]: info: Loading plugin "system"...
Sep 01 01:27:02 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10.
Sep 01 01:27:02 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:27:02 stefans-speaker volumio[24258]: info: Loading plugin "appearance"...
Sep 01 01:27:02 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:27:02 stefans-speaker go-librespot[24282]: go-librespot daemon starting...
Sep 01 01:27:02 stefans-speaker go-librespot[24286]: time="2026-09-01T01:27:02+02:00" level=info msg="running go-librespot 0.4.0"
Sep 01 01:27:02 stefans-speaker go-librespot[24286]: time="2026-09-01T01:27:02+02:00" level=debug msg="app state loaded"
Sep 01 01:27:02 stefans-speaker go-librespot[24286]: time="2026-09-01T01:27:02+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Sep 01 01:27:02 stefans-speaker go-librespot[24286]: time="2026-09-01T01:27:02+02: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]"
Sep 01 01:27:02 stefans-speaker go-librespot[24286]: time="2026-09-01T01:27:02+02: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]"
Sep 01 01:27:02 stefans-speaker go-librespot[24286]: time="2026-09-01T01:27:02+02: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]"
Sep 01 01:27:02 stefans-speaker go-librespot[24286]: time="2026-09-01T01:27:02+02:00" level=info msg="zeroconf server listening on port 40279"
Sep 01 01:27:02 stefans-speaker go-librespot[24286]: time="2026-09-01T01:27:02+02:00" level=debug msg="obtained new client token: AAG07bpNvXbXY27PNIkVAD5EMdDQod3LadiOYro0L2h4yeE6Q4XIWd+dRpkPZS49ZdNfUBknR90INQihgqTUAPvZg/FP+JHQSEhCdGOHHEKvN/3PoY0Ww8fDfMvAZtKJHTWsO7iV4dOXYtz0Jpa5dDZHWpU9RlFMpNwki/rgE4eE04Kf2owCF5box+4iL5vIIAb/8TZEG8zrKUfl30BDV63Dz2dolDXpoh9dQ2c6yXxolQezBp2waZ31m6k="
Sep 01 01:27:02 stefans-speaker go-librespot[24286]: time="2026-09-01T01:27:02+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Sep 01 01:27:02 stefans-speaker go-librespot[24286]: time="2026-09-01T01:27:02+02:00" level=debug msg="completed keyexchange"
Sep 01 01:27:02 stefans-speaker go-librespot[24286]: time="2026-09-01T01:27:02+02:00" level=debug msg="completed challenge"
Sep 01 01:27:02 stefans-speaker go-librespot[24286]: time="2026-09-01T01:27:02+02:00" level=info msg="authenticated AP" username="31************************cy"
Sep 01 01:27:03 stefans-speaker go-librespot[24286]: time="2026-09-01T01:27:03+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Sep 01 01:27:03 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Sep 01 01:27:03 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Sep 01 01:27:03 stefans-speaker volumio[24258]: info: Loading plugin "network"...
Sep 01 01:27:03 stefans-speaker volumio[24258]: info: Refreshing Cached IP Addresses
Sep 01 01:27:03 stefans-speaker sudo[24295]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:27:03 stefans-speaker volumio[24258]: info: Loading plugin "services"...
Sep 01 01:27:03 stefans-speaker sudo[24297]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:27:03 stefans-speaker sudo[24295]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Sep 01 01:27:03 stefans-speaker volumio[24258]: info: Loading plugin "alsa_controller"...
Sep 01 01:27:03 stefans-speaker sudo[24295]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:27:03 stefans-speaker sudo[24295]: pam_unix(sudo:session): session closed for user root
Sep 01 01:27:03 stefans-speaker sudo[24297]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 01 01:27:03 stefans-speaker sudo[24297]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:27:03 stefans-speaker sudo[24297]: pam_unix(sudo:session): session closed for user root
Sep 01 01:27:03 stefans-speaker sudo[24304]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:27:03 stefans-speaker sudo[24304]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Sep 01 01:27:03 stefans-speaker sudo[24304]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:27:03 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Sep 01 01:27:03 stefans-speaker volumio[24258]: info: Loading plugin "wizard"...
Sep 01 01:27:03 stefans-speaker volumio[24258]: info: Loading plugin "networkfs"...
Sep 01 01:27:03 stefans-speaker volumio[24258]: info: Starting Udev Watcher for removable devices
Sep 01 01:27:03 stefans-speaker volumio[24258]: info: Ignoring mount for partition: boot
Sep 01 01:27:03 stefans-speaker volumio[24258]: info: Ignoring mount for partition: volumio
Sep 01 01:27:03 stefans-speaker volumio[24258]: info: Ignoring mount for partition: volumio_data
Sep 01 01:27:03 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Sep 01 01:27:03 stefans-speaker volumio[24258]: info: Loading plugin "volumio_command_line_client"...
Sep 01 01:27:03 stefans-speaker volumio[24258]: info: Loading plugin "upnp"...
Sep 01 01:27:03 stefans-speaker volumio[24258]: info: [1788218823684] Starting Upmpd Daemon
Sep 01 01:27:03 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Sep 01 01:27:03 stefans-speaker volumio[24258]: info: Loading plugin "my_music"...
Sep 01 01:27:03 stefans-speaker volumio[24258]: info: Loading plugin "mpd"...
Sep 01 01:27:04 stefans-speaker volumio[24258]: info: Loading plugin "upnp_browser"...
Sep 01 01:27:04 stefans-speaker volumio-remote-updater[679]: [2026-09-01 01:27:04] [connect] Successful connection
Sep 01 01:27:05 stefans-speaker volumio[24258]: info: Starting UPNP Browser
Sep 01 01:27:05 stefans-speaker volumio[24258]: info: Loading plugin "alarm-clock"...
Sep 01 01:27:05 stefans-speaker volumio[24258]: info: Loading plugin "airplay_emulation"...
Sep 01 01:27:05 stefans-speaker volumio[24258]: info: Starting Shairport Sync
Sep 01 01:27:05 stefans-speaker volumio[24258]: info: Loading plugin "last_100"...
Sep 01 01:27:05 stefans-speaker volumio[24258]: info: Loading plugin "webradio"...
Sep 01 01:27:05 stefans-speaker volumio[24258]: info: Loading plugin "i2s_dacs"...
Sep 01 01:27:05 stefans-speaker volumio[24258]: info: I2S DAC not set, start Auto-detection
Sep 01 01:27:05 stefans-speaker volumio[24258]: info: Loading plugin "volumiodiscovery"...
Sep 01 01:27:05 stefans-speaker volumio[24258]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Sep 01 01:27:05 stefans-speaker volumio[24258]: *** WARNING *** Please fix your application to use the native API of Avahi!
Sep 01 01:27:05 stefans-speaker volumio[24258]: *** WARNING *** For more information see 
Sep 01 01:27:05 stefans-speaker volumio[24258]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Sep 01 01:27:05 stefans-speaker volumio[24258]: *** WARNING *** Please fix your application to use the native API of Avahi!
Sep 01 01:27:05 stefans-speaker node[24258]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Sep 01 01:27:05 stefans-speaker volumio[24258]: *** WARNING *** For more information see 
Sep 01 01:27:05 stefans-speaker node[24258]: *** WARNING *** Please fix your application to use the native API of Avahi!
Sep 01 01:27:05 stefans-speaker node[24258]: *** WARNING *** For more information see 
Sep 01 01:27:05 stefans-speaker node[24258]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Sep 01 01:27:05 stefans-speaker node[24258]: *** WARNING *** Please fix your application to use the native API of Avahi!
Sep 01 01:27:05 stefans-speaker node[24258]: *** WARNING *** For more information see 
Sep 01 01:27:05 stefans-speaker volumio[24258]: info: Applying required configuration parameters for plugin volumiodiscovery
Sep 01 01:27:05 stefans-speaker volumio[24258]: info: Discovery: Started advertising with name: Stefan’s Speaker
Sep 01 01:27:06 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Sep 01 01:27:06 stefans-speaker volumio[24258]: info: Loading plugin "spop"...
Sep 01 01:27:06 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11.
Sep 01 01:27:06 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:27:06 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:27:06 stefans-speaker go-librespot[24330]: go-librespot daemon starting...
Sep 01 01:27:06 stefans-speaker go-librespot[24331]: time="2026-09-01T01:27:06+02:00" level=info msg="running go-librespot 0.4.0"
Sep 01 01:27:06 stefans-speaker go-librespot[24331]: time="2026-09-01T01:27:06+02:00" level=debug msg="app state loaded"
Sep 01 01:27:06 stefans-speaker go-librespot[24331]: time="2026-09-01T01:27:06+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Sep 01 01:27:06 stefans-speaker go-librespot[24331]: time="2026-09-01T01:27:06+02: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]"
Sep 01 01:27:06 stefans-speaker go-librespot[24331]: time="2026-09-01T01:27:06+02: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]"
Sep 01 01:27:06 stefans-speaker go-librespot[24331]: time="2026-09-01T01:27:06+02: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]"
Sep 01 01:27:06 stefans-speaker go-librespot[24331]: time="2026-09-01T01:27:06+02:00" level=info msg="zeroconf server listening on port 36145"
Sep 01 01:27:06 stefans-speaker sudo[24304]: pam_unix(sudo:session): session closed for user root
Sep 01 01:27:06 stefans-speaker go-librespot[24331]: time="2026-09-01T01:27:06+02:00" level=debug msg="obtained new client token: AAEwxeGnAsgu5bNHa82w0y0ReBLJB/JVCOaXF2jE9PSbgzp0Cz+u4N6Oa9Jb3Qb2WodODXFIHE4V/f588wFU6aHRVY6B7paBAcWD+bVmOQpnQpB7hhIwnzyEWsMhhL8AqnXYWRkPlaV9PKxr09UEVuAQ+iTAXzxNW8Y+k/DwX/G+743Cmp7TulgKSyORFfJt750KbnR4QhQ60j6lOGg7gF7Cj/3El1m9QT6VuKaw7QUFlxSFQhFw+iW+xkA="
Sep 01 01:27:07 stefans-speaker go-librespot[24331]: time="2026-09-01T01:27:07+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Sep 01 01:27:07 stefans-speaker go-librespot[24331]: time="2026-09-01T01:27:07+02:00" level=debug msg="completed keyexchange"
Sep 01 01:27:07 stefans-speaker go-librespot[24331]: time="2026-09-01T01:27:07+02:00" level=debug msg="completed challenge"
Sep 01 01:27:07 stefans-speaker volumio[24258]: info: Loading plugin "ytcr"...
Sep 01 01:27:07 stefans-speaker go-librespot[24331]: time="2026-09-01T01:27:07+02:00" level=info msg="authenticated AP" username="31************************cy"
Sep 01 01:27:07 stefans-speaker go-librespot[24331]: time="2026-09-01T01:27:07+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Sep 01 01:27:07 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Sep 01 01:27:07 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Sep 01 01:27:08 stefans-speaker volumio[24258]: info: Loading plugin "outputs"...
Sep 01 01:27:08 stefans-speaker volumio[24258]: info: Loading plugin "albumart"...
Sep 01 01:27:08 stefans-speaker volumio[24258]: info: Plugin example_plugin is not enabled
Sep 01 01:27:08 stefans-speaker volumio[24258]: info: Loading plugin "inputs"...
Sep 01 01:27:08 stefans-speaker volumio[24258]: info: Loading plugin "updater_comm"...
Sep 01 01:27:08 stefans-speaker volumio[24258]: info: Plugin mpdemulation is not enabled
Sep 01 01:27:08 stefans-speaker volumio[24258]: info: Loading plugin "rest_api"...
Sep 01 01:27:08 stefans-speaker volumio[24258]: info: Loading plugin "websocket"...
Sep 01 01:27:08 stefans-speaker volumio[24258]: info: Starting Socket.io Server version 1.7.4
Sep 01 01:27:08 stefans-speaker volumio[24258]: info: Loading i18n strings for locale nl
Sep 01 01:27:08 stefans-speaker volumio[24258]: Updating browse sources language
Sep 01 01:27:08 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 01 01:27:08 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Sep 01 01:27:08 stefans-speaker volumio[24258]: info: CoreCommandRouter::initPlayerControls
Sep 01 01:27:08 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:08 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:08 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:08 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:08 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:08 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:08 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:08 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:08 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Sep 01 01:27:08 stefans-speaker volumio[24258]: Express server listening on port 3000
Sep 01 01:27:08 stefans-speaker volumio[24258]:  [Metrics]  WebUI:  8s 131.21ms 
Sep 01 01:27:08 stefans-speaker volumio[24258]: info: CoreStateMachine::resetVolumioState
Sep 01 01:27:08 stefans-speaker volumio[24258]: info: CoreStateMachine::getcurrentVolume
Sep 01 01:27:08 stefans-speaker volumio[24258]: info: CoreCommandRouter::volumioRetrievevolume
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: Cannot read play queue from file
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: Volumio Network Manager: Network status updated: 2
Sep 01 01:27:09 stefans-speaker volumio[24338]: Forking 3 albumart workers
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: VolumeController:: Volume=70 Mute =false
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CoreStateMachine::pushState
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CorePlayQueue::getTrack 0
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CoreCommandRouter::volumioPushState
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CoreStateMachine::updateTrackBlock
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CorePlayQueue::getTrackBlock
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CoreCommandRouter::volumioRetrievevolume
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CoreStateMachine::setRepeat null single undefined
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CoreStateMachine::pushState
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CorePlayQueue::getTrack 0
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CoreCommandRouter::volumioPushState
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CoreStateMachine::setRandom null
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CoreStateMachine::pushState
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CorePlayQueue::getTrack 0
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CoreCommandRouter::volumioPushState
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: Setting Device type: Raspberry PI
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: VolumeController:: Volume=70 Mute =false
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CoreStateMachine::pushState
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CorePlayQueue::getTrack 0
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CoreCommandRouter::volumioPushState
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: Completed loading Core Plugins
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: Preparing to generate the ALSA configuration file
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: Discovery: adding a312d0fa-c0eb-45ad-a25b-79fcdf237e8a
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: Discovery: Found device Stefan’s Speaker
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CoreCommandRouter::volumioGetState
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CorePlayQueue::getTrack 0
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: Discovery: this is already registered,  a312d0fa-c0eb-45ad-a25b-79fcdf237e8a
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: Discovery: Found device Stefan’s Speaker
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CoreCommandRouter::volumioGetState
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CorePlayQueue::getTrack 0
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: Asound.conf file unchanged, so no further update is needed
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: Output device has changed, restarting MPD
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: Output device has changed, restarting Shairport Sync
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:27:09 stefans-speaker sudo[24396]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:27:09 stefans-speaker sudo[24398]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:27:09 stefans-speaker sudo[24396]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Sep 01 01:27:09 stefans-speaker sudo[24396]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:27:09 stefans-speaker sudo[24398]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Sep 01 01:27:09 stefans-speaker sudo[24396]: pam_unix(sudo:session): session closed for user root
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Sep 01 01:27:09 stefans-speaker sudo[24398]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: ___________ START PLUGINS ___________
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: ControllerMpd::onStart: Initializing MPD
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: Creating MPD Configuration file
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: [1788218829866] CoreMusicLibrary::Adding element Media Servers
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 01 01:27:09 stefans-speaker systemd[1]: Stopping mpd.service - Music Player Daemon...
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: UPNP Browser: Client initialized successfully
Sep 01 01:27:09 stefans-speaker sudo[24406]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:27:09 stefans-speaker sudo[24406]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Sep 01 01:27:09 stefans-speaker sudo[24408]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:09 stefans-speaker sudo[24406]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:27:09 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:27:09 stefans-speaker sudo[24408]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Sep 01 01:27:09 stefans-speaker sudo[24408]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:27:09 stefans-speaker systemd[1]: mpd.service: Deactivated successfully.
Sep 01 01:27:09 stefans-speaker systemd[1]: Stopped mpd.service - Music Player Daemon.
Sep 01 01:27:09 stefans-speaker systemd[1]: mpd.service: Consumed 4.436s CPU time.
Sep 01 01:27:09 stefans-speaker systemd[1]: mpd.socket: Deactivated successfully.
Sep 01 01:27:09 stefans-speaker sudo[24406]: pam_unix(sudo:session): session closed for user root
Sep 01 01:27:09 stefans-speaker systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Sep 01 01:27:09 stefans-speaker systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Sep 01 01:27:10 stefans-speaker volumio[24258]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Sep 01 01:27:10 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:10 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:27:10 stefans-speaker systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Sep 01 01:27:10 stefans-speaker systemd[1]: Starting mpd.service - Music Player Daemon...
Sep 01 01:27:10 stefans-speaker volumio[24258]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Sep 01 01:27:10 stefans-speaker volumio[24258]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Sep 01 01:27:10 stefans-speaker volumio[24258]: info: [1788218830105] CoreMusicLibrary::Adding element Last_100
Sep 01 01:27:10 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 01 01:27:10 stefans-speaker systemd[1]: mpd.service: Deactivated successfully.
Sep 01 01:27:10 stefans-speaker systemd[1]: Stopped mpd.service - Music Player Daemon.
Sep 01 01:27:10 stefans-speaker volumio[24258]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Sep 01 01:27:10 stefans-speaker volumio[24258]: info: [1788218830123] CoreMusicLibrary::Adding element Webradio
Sep 01 01:27:10 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 01 01:27:10 stefans-speaker systemd[1]: mpd.socket: Deactivated successfully.
Sep 01 01:27:10 stefans-speaker systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Sep 01 01:27:10 stefans-speaker systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Sep 01 01:27:10 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Sep 01 01:27:10 stefans-speaker systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Sep 01 01:27:10 stefans-speaker systemd[1]: Starting mpd.service - Music Player Daemon...
Sep 01 01:27:10 stefans-speaker volumio[24258]: info: Initializing BBC Radios
Sep 01 01:27:10 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Sep 01 01:27:10 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:27:10 stefans-speaker volumio[24258]: info: Creating Spotify config file
Sep 01 01:27:10 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:10 stefans-speaker sudo[24422]:     root : unable to resolve host stefans-speaker: System error
Sep 01 01:27:10 stefans-speaker sudo[24422]: sudo: unable to resolve host stefans-speaker: System error
Sep 01 01:27:10 stefans-speaker sudo[24422]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Sep 01 01:27:10 stefans-speaker sudo[24422]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Sep 01 01:27:10 stefans-speaker sudo[24422]: pam_unix(sudo:session): session closed for user root
Sep 01 01:27:10 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12.
Sep 01 01:27:10 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:27:10 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:27:10 stefans-speaker go-librespot[24438]: go-librespot daemon starting...
Sep 01 01:27:10 stefans-speaker go-librespot[24439]: time="2026-09-01T01:27:10+02:00" level=info msg="running go-librespot 0.4.0"
Sep 01 01:27:10 stefans-speaker volumio[24258]: info: Volumio Calling Home
Sep 01 01:27:11 stefans-speaker go-librespot[24439]: time="2026-09-01T01:27:11+02:00" level=info msg="zeroconf server listening on port 40477"
Sep 01 01:27:11 stefans-speaker volumio[24355]: Starting albumart workers
Sep 01 01:27:11 stefans-speaker volumio[24356]: Starting albumart workers
Sep 01 01:27:11 stefans-speaker volumio[24354]: Starting albumart workers
Sep 01 01:27:11 stefans-speaker volumio[24258]: info: MPD Permissions set
Sep 01 01:27:11 stefans-speaker volumio[24258]: info: MPD Permissions set
Sep 01 01:27:11 stefans-speaker volumio[24258]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1
Sep 01 01:27:11 stefans-speaker volumio[24258]: info: Spotify config file written
Sep 01 01:27:11 stefans-speaker sudo[24451]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:27:11 stefans-speaker sudo[24451]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Sep 01 01:27:11 stefans-speaker sudo[24451]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:27:11 stefans-speaker systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon...
Sep 01 01:27:11 stefans-speaker systemd[1]: go-librespot-daemon.service: Killing process 24447 (go-librespot) with signal SIGKILL.
Sep 01 01:27:11 stefans-speaker systemd[1]: go-librespot-daemon.service: Deactivated successfully.
Sep 01 01:27:11 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:27:11 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:27:11 stefans-speaker go-librespot[24453]: go-librespot daemon starting...
Sep 01 01:27:12 stefans-speaker sudo[24451]: pam_unix(sudo:session): session closed for user root
Sep 01 01:27:12 stefans-speaker go-librespot[24454]: time="2026-09-01T01:27:12+02:00" level=info msg="running go-librespot 0.4.0"
Sep 01 01:27:12 stefans-speaker go-librespot[24454]: time="2026-09-01T01:27:12+02:00" level=debug msg="app state loaded"
Sep 01 01:27:12 stefans-speaker go-librespot[24454]: time="2026-09-01T01:27:12+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Sep 01 01:27:12 stefans-speaker volumio[24258]: info: Volumio called home
Sep 01 01:27:12 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:12 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:12 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:12 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:12 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:12 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:12 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:12 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:12 stefans-speaker go-librespot[24454]: time="2026-09-01T01:27:12+02: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]"
Sep 01 01:27:12 stefans-speaker go-librespot[24454]: time="2026-09-01T01:27:12+02: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]"
Sep 01 01:27:12 stefans-speaker go-librespot[24454]: time="2026-09-01T01:27:12+02: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]"
Sep 01 01:27:12 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:27:12 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:12 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:12 stefans-speaker go-librespot[24454]: time="2026-09-01T01:27:12+02:00" level=info msg="zeroconf server listening on port 37371"
Sep 01 01:27:12 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:12 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:12 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:12 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:12 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:12 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:12 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:12 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:27:12 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 01 01:27:12 stefans-speaker volumio[24258]: info: No need to fix Spotify hosts
Sep 01 01:27:12 stefans-speaker go-librespot[24454]: time="2026-09-01T01:27:12+02:00" level=debug msg="obtained new client token: AAHaSM2Z0O338bVaZFqV/rbTLlwFOifmk0j7IuShmNd90kWruIOfwsh1L2R7fWvs8UwF9Xg6viwkHqBcdYj1uragbXXbRDgmF9A8F/wu3W6gYsbecTEyLMb+Omb+dD3h74+RO1R+xAo6Tg6xLmlcIfxTjvzRPEKRs3Xc29KHwricJ+KAd8sE14j5AyoJTp5LTTrz0iEaODCNlhfvtHt4bS57PLxCFZ4axuPmRtfNE1ZnjUkxZ8Zzn4zpZVo="
Sep 01 01:27:12 stefans-speaker go-librespot[24454]: time="2026-09-01T01:27:12+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Sep 01 01:27:12 stefans-speaker go-librespot[24454]: time="2026-09-01T01:27:12+02:00" level=debug msg="completed keyexchange"
Sep 01 01:27:12 stefans-speaker go-librespot[24454]: time="2026-09-01T01:27:12+02:00" level=debug msg="completed challenge"
Sep 01 01:27:12 stefans-speaker go-librespot[24454]: time="2026-09-01T01:27:12+02:00" level=info msg="authenticated AP" username="31************************cy"
Sep 01 01:27:12 stefans-speaker volumio[24258]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Sep 01 01:27:12 stefans-speaker volumio[24258]: SPOTIFY: BQCoy7jTPX6zH1PYxSBloJ0gA1JmAS3d53ygiw_M9fGd9fBPtsJtX934ebp53hzNIBYWLo7_PKVG7G1wRCF6Vpbay7XibzPlZoi0pGZ0jhfk__EavseOCgnlgkNk-6a-G2I2isJlZKInXvPHQEaTgvyzlQplswAR7kX63Zq1WVjB4bgosl4F85D8P_aCwEW7ssQV3RJkcyVFWePrB8xoo846fSz04R1IVQTvMtiLK58-3-659kMFWe6EHUjpSfpNhiydOdO-CNYw4Xkb0sIKiME1WBPHFMg3swvwtELuUsGZF8x82dojQoXi-4Kpang
Sep 01 01:27:12 stefans-speaker volumio[24258]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Sep 01 01:27:12 stefans-speaker volumio[24258]: info: New Spotify access token = BQCoy7jTPX6zH1PYxSBloJ0gA1JmAS3d53ygiw_M9fGd9fBPtsJtX934ebp53hzNIBYWLo7_PKVG7G1wRCF6Vpbay7XibzPlZoi0pGZ0jhfk__EavseOCgnlgkNk-6a-G2I2isJlZKInXvPHQEaTgvyzlQplswAR7kX63Zq1WVjB4bgosl4F85D8P_aCwEW7ssQV3RJkcyVFWePrB8xoo846fSz04R1IVQTvMtiLK58-3-659kMFWe6EHUjpSfpNhiydOdO-CNYw4Xkb0sIKiME1WBPHFMg3swvwtELuUsGZF8x82dojQoXi-4Kpang
Sep 01 01:27:12 stefans-speaker volumio[24258]: info: Spotify credentials grant success - running version from March 24, 2019
Sep 01 01:27:12 stefans-speaker go-librespot[24454]: time="2026-09-01T01:27:12+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Sep 01 01:27:12 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Sep 01 01:27:12 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Sep 01 01:27:12 stefans-speaker volumio[24258]: info: Starting Shairport Sync
Sep 01 01:27:12 stefans-speaker volumio[24258]: info: Starting Shairport Sync
Sep 01 01:27:13 stefans-speaker volumio[24258]: info: Starting Shairport Sync
Sep 01 01:27:13 stefans-speaker sudo[24490]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:27:13 stefans-speaker sudo[24490]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Sep 01 01:27:13 stefans-speaker sudo[24490]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:27:13 stefans-speaker sudo[24492]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:27:13 stefans-speaker sudo[24492]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Sep 01 01:27:13 stefans-speaker sudo[24492]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:27:13 stefans-speaker sudo[24494]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:27:13 stefans-speaker sudo[24494]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Sep 01 01:27:13 stefans-speaker sudo[24494]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:27:13 stefans-speaker systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Sep 01 01:27:13 stefans-speaker systemd[1]: shairport-sync.service: Deactivated successfully.
Sep 01 01:27:13 stefans-speaker systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Sep 01 01:27:13 stefans-speaker systemd[1]: shairport-sync.service: Consumed 1.950s CPU time.
Sep 01 01:27:13 stefans-speaker systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Sep 01 01:27:13 stefans-speaker sudo[24490]: pam_unix(sudo:session): session closed for user root
Sep 01 01:27:13 stefans-speaker sudo[24492]: pam_unix(sudo:session): session closed for user root
Sep 01 01:27:13 stefans-speaker systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Sep 01 01:27:13 stefans-speaker systemd[1]: shairport-sync.service: Deactivated successfully.
Sep 01 01:27:13 stefans-speaker systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Sep 01 01:27:13 stefans-speaker volumio[24258]: info: Shairport-Sync Started
Sep 01 01:27:13 stefans-speaker volumio[24258]: Error adding Membership: Error: addMembership EINVAL
Sep 01 01:27:13 stefans-speaker systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Sep 01 01:27:13 stefans-speaker sudo[24494]: pam_unix(sudo:session): session closed for user root
Sep 01 01:27:13 stefans-speaker volumio[24258]: info: CoreCommandRouter::volumioGetState
Sep 01 01:27:13 stefans-speaker volumio[24258]: info: CorePlayQueue::getTrack 0
Sep 01 01:27:13 stefans-speaker volumio[24258]: info: Shairport-Sync Started
Sep 01 01:27:13 stefans-speaker volumio[24258]: info: Shairport-Sync Started
Sep 01 01:27:13 stefans-speaker volumio[24258]: SPOTIFY: User informations: {"account_id":"zltuAJDW9c","country":"RO","display_name":"emanueluss","email":"emanuel.grecescu@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31mmtxvuufe76qdkk6caepwk3fcy"},"followers":{"href":null,"total":3},"href":"https://api.spotify.com/v1/users/31mmtxvuufe76qdkk6caepwk3fcy","id":"31mmtxvuufe76qdkk6caepwk3fcy","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee852e7ddfcb02af85c1462f3412","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b822e7ddfcb02af85c1462f3412","width":64}],"product":"premium","type":"user","uri":"spotify:user:31mmtxvuufe76qdkk6caepwk3fcy"}
Sep 01 01:27:13 stefans-speaker volumio[24258]: info: Spotify Successfully logged in
Sep 01 01:27:13 stefans-speaker volumio[24258]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Sep 01 01:27:13 stefans-speaker volumio[24258]: info: [1788218833405] CoreMusicLibrary::Adding element Spotify
Sep 01 01:27:13 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 01 01:27:13 stefans-speaker volumio[24258]: Cannot find translation for source Spotify
Sep 01 01:27:13 stefans-speaker volumio[24258]: info: [yt-cast-receiver] DIAL server listening on port 8098
Sep 01 01:27:13 stefans-speaker volumio[24258]: info: CoreCommandRouter::volumioRetrievevolume
Sep 01 01:27:13 stefans-speaker sudo[24532]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:27:13 stefans-speaker sudo[24532]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 01 01:27:13 stefans-speaker sudo[24532]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:27:13 stefans-speaker volumio[24258]: info: VolumeController:: Volume=70 Mute =false
Sep 01 01:27:13 stefans-speaker volumio[24258]: info: CoreCommandRouter::volumioGetState
Sep 01 01:27:13 stefans-speaker volumio[24258]: info: CorePlayQueue::getTrack 0
Sep 01 01:27:13 stefans-speaker volumio[24258]: info: CoreStateMachine::pushState
Sep 01 01:27:13 stefans-speaker volumio[24258]: info: CorePlayQueue::getTrack 0
Sep 01 01:27:13 stefans-speaker volumio[24258]: info: CoreCommandRouter::volumioPushState
Sep 01 01:27:13 stefans-speaker sudo[24532]: pam_unix(sudo:session): session closed for user root
Sep 01 01:27:13 stefans-speaker sudo[24530]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:27:13 stefans-speaker sudo[24530]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Sep 01 01:27:13 stefans-speaker sudo[24530]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:27:13 stefans-speaker sudo[24536]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:27:13 stefans-speaker sudo[24530]: pam_unix(sudo:session): session closed for user root
Sep 01 01:27:13 stefans-speaker sudo[24536]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Sep 01 01:27:13 stefans-speaker sudo[24536]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:27:13 stefans-speaker sudo[24536]: pam_unix(sudo:session): session closed for user root
Sep 01 01:27:14 stefans-speaker volumio[24258]: info: Upmpdcli Daemon Started
Sep 01 01:27:14 stefans-speaker mpd[24437]: 2026-09-01T01:27:14 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Sep 01 01:27:14 stefans-speaker systemd[1]: Started mpd.service - Music Player Daemon.
Sep 01 01:27:14 stefans-speaker sudo[24398]: pam_unix(sudo:session): session closed for user root
Sep 01 01:27:14 stefans-speaker sudo[24408]: pam_unix(sudo:session): session closed for user root
Sep 01 01:27:15 stefans-speaker volumio[24258]: error: MPD error: The expression evaluated to a falsy value:
Sep 01 01:27:15 stefans-speaker volumio[24258]:   assert.ok(self.idling)
Sep 01 01:27:15 stefans-speaker volumio[24258]: error: The expression evaluated to a falsy value:
Sep 01 01:27:15 stefans-speaker volumio[24258]:   assert.ok(self.idling)
Sep 01 01:27:15 stefans-speaker volumio[24258]: info: MPD running with PID24437
Sep 01 01:27:15 stefans-speaker volumio[24258]:  ,establishing connection
Sep 01 01:27:15 stefans-speaker volumio[24258]: error: updateQueue error: null
Sep 01 01:27:15 stefans-speaker volumio[24258]: info: Completed starting Core Plugins
Sep 01 01:27:15 stefans-speaker volumio[24258]: info: -------------------------------------------
Sep 01 01:27:15 stefans-speaker volumio[24258]: info: -----    MyVolumio plugins startup     ----
Sep 01 01:27:15 stefans-speaker volumio[24258]: info: -------------------------------------------
Sep 01 01:27:15 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Fetching plans data....
Sep 01 01:27:15 stefans-speaker volumio[24258]: error: updateQueue error: null
Sep 01 01:27:15 stefans-speaker volumio[24258]: info: go-librespot daemon successfully initialized
Sep 01 01:27:16 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Sep 01 01:27:16 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:27:16 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:27:16 stefans-speaker go-librespot[24545]: go-librespot daemon starting...
Sep 01 01:27:16 stefans-speaker go-librespot[24546]: time="2026-09-01T01:27:16+02:00" level=info msg="running go-librespot 0.4.0"
Sep 01 01:27:16 stefans-speaker go-librespot[24546]: time="2026-09-01T01:27:16+02:00" level=debug msg="app state loaded"
Sep 01 01:27:16 stefans-speaker go-librespot[24546]: time="2026-09-01T01:27:16+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Sep 01 01:27:16 stefans-speaker go-librespot[24546]: time="2026-09-01T01:27:16+02: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]"
Sep 01 01:27:16 stefans-speaker go-librespot[24546]: time="2026-09-01T01:27:16+02: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]"
Sep 01 01:27:16 stefans-speaker go-librespot[24546]: time="2026-09-01T01:27:16+02: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]"
Sep 01 01:27:16 stefans-speaker go-librespot[24546]: time="2026-09-01T01:27:16+02:00" level=info msg="zeroconf server listening on port 32983"
Sep 01 01:27:16 stefans-speaker go-librespot[24546]: time="2026-09-01T01:27:16+02:00" level=debug msg="obtained new client token: AAEDvrfhqekGT/YoPz0qw/H3nwZnQP/vv+OwlYnpPzjTizaZbhC2IZz4kX+0fF9Gs3WG9RkXi5/BtXqfkLfUtXGOfTW05CLimhUhOw+J2h7qV6Lc0P2uVo1JHVqWv3TB6vUvXEA7AMbb8+hxkWVacZH6VDjwgEZCa/zMTef0/27ipoN56ucp+82m+coerJPxMAqNIUyaO94LOldrZCYgvHEQrxh/7dHIu9+gyPCdNoOGA5mmHza/RYFofrc="
Sep 01 01:27:16 stefans-speaker go-librespot[24546]: time="2026-09-01T01:27:16+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Sep 01 01:27:16 stefans-speaker volumio-remote-updater[679]: [2026-09-01 01:27:16] [connect] Successful connection
Sep 01 01:27:16 stefans-speaker volumio-remote-updater[679]: [2026-09-01 01:27:16] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788218836 101
Sep 01 01:27:16 stefans-speaker volumio[24258]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 2
Sep 01 01:27:16 stefans-speaker go-librespot[24546]: time="2026-09-01T01:27:16+02:00" level=debug msg="completed keyexchange"
Sep 01 01:27:16 stefans-speaker go-librespot[24546]: time="2026-09-01T01:27:16+02:00" level=debug msg="completed challenge"
Sep 01 01:27:16 stefans-speaker go-librespot[24546]: time="2026-09-01T01:27:16+02:00" level=info msg="authenticated AP" username="31************************cy"
Sep 01 01:27:16 stefans-speaker go-librespot[24546]: time="2026-09-01T01:27:16+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Sep 01 01:27:16 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Sep 01 01:27:16 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Sep 01 01:27:17 stefans-speaker sudo[24556]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:27:18 stefans-speaker sudo[24558]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:27:18 stefans-speaker sudo[24556]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Sep 01 01:27:18 stefans-speaker sudo[24556]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:27:18 stefans-speaker sudo[24558]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service
Sep 01 01:27:18 stefans-speaker sudo[24558]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:27:18 stefans-speaker systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service...
Sep 01 01:27:18 stefans-speaker systemd[1]: mpd_monitor.service: Deactivated successfully.
Sep 01 01:27:18 stefans-speaker systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service.
Sep 01 01:27:18 stefans-speaker systemd[1]: Started mpd_monitor.service - MPD Monitor Service.
Sep 01 01:27:18 stefans-speaker sudo[24556]: pam_unix(sudo:session): session closed for user root
Sep 01 01:27:18 stefans-speaker sudo[24558]: pam_unix(sudo:session): session closed for user root
Sep 01 01:27:18 stefans-speaker volumio[24258]: info: Successfully started MPD Monitor
Sep 01 01:27:18 stefans-speaker mpd_monitor.sh[24561]: MPD Monitor Service: Starting MPD Monitor Service
Sep 01 01:27:18 stefans-speaker volumio[24258]: info: Successfully started MPD Monitor
Sep 01 01:27:18 stefans-speaker volumio[24258]: info: Initializing connection to go-librespot Websocket
Sep 01 01:27:18 stefans-speaker volumio[24258]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Sep 01 01:27:19 stefans-speaker volumio[24258]: error: Failed LSINFO: Error:  [50@0] {lsinfo} No such directory
Sep 01 01:27:20 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Sep 01 01:27:20 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:27:20 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:27:20 stefans-speaker go-librespot[24565]: go-librespot daemon starting...
Sep 01 01:27:20 stefans-speaker go-librespot[24566]: time="2026-09-01T01:27:20+02:00" level=info msg="running go-librespot 0.4.0"
Sep 01 01:27:20 stefans-speaker go-librespot[24566]: time="2026-09-01T01:27:20+02:00" level=debug msg="app state loaded"
Sep 01 01:27:20 stefans-speaker go-librespot[24566]: time="2026-09-01T01:27:20+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Sep 01 01:27:20 stefans-speaker go-librespot[24566]: time="2026-09-01T01:27:20+02: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]"
Sep 01 01:27:20 stefans-speaker go-librespot[24566]: time="2026-09-01T01:27:20+02: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]"
Sep 01 01:27:20 stefans-speaker go-librespot[24566]: time="2026-09-01T01:27:20+02: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]"
Sep 01 01:27:20 stefans-speaker go-librespot[24566]: time="2026-09-01T01:27:20+02:00" level=info msg="zeroconf server listening on port 44973"
Sep 01 01:27:20 stefans-speaker go-librespot[24566]: time="2026-09-01T01:27:20+02:00" level=debug msg="obtained new client token: AAG+qNTUkNUmG+LJj9e22CwEW0VvGEENftbyxi634YMJB74v0JTUlr3Ty8W11UDn9p8ybSsf3Mlb6zKDx3Hxf9wn70g1scEjEtv3AOc7V56Ct1eRvWg6zs18qSP2M0hZ4zBeOuIg9HNSu82pIA16ORvoGckVtCd36ZTLVy++crh3Ey69UBtfX1DBxXf2sT03sxxyQiRHzI85rU7Z9/Z4e/QNeLKSAb+N2wmi92Vj+OK/qqLeB0ConSIqt/c="
Sep 01 01:27:20 stefans-speaker go-librespot[24566]: time="2026-09-01T01:27:20+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Sep 01 01:27:20 stefans-speaker go-librespot[24566]: time="2026-09-01T01:27:20+02:00" level=debug msg="completed keyexchange"
Sep 01 01:27:20 stefans-speaker go-librespot[24566]: time="2026-09-01T01:27:20+02:00" level=debug msg="completed challenge"
Sep 01 01:27:20 stefans-speaker go-librespot[24566]: time="2026-09-01T01:27:20+02:00" level=info msg="authenticated AP" username="31************************cy"
Sep 01 01:27:20 stefans-speaker go-librespot[24566]: time="2026-09-01T01:27:20+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Sep 01 01:27:20 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Sep 01 01:27:20 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Sep 01 01:27:21 stefans-speaker volumio[24258]: info: Initializing connection to go-librespot Websocket
Sep 01 01:27:21 stefans-speaker volumio[24258]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: Adding plugin bluetooth to MyMusic Plugins
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: Adding plugin multiroom to MyMusic Plugins
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: Adding plugin metavolumio to MyMusic Plugins
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: Adding plugin cd_controller to MyMusic Plugins
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: Adding plugin qobuzconnect to MyMusic Plugins
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: Adding plugin smart_inputs to MyMusic Plugins
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: Adding plugin tidalconnect to MyMusic Plugins
Sep 01 01:27:23 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Sep 01 01:27:24 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Sep 01 01:27:24 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:27:24 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:27:24 stefans-speaker go-librespot[24590]: go-librespot daemon starting...
Sep 01 01:27:24 stefans-speaker go-librespot[24591]: time="2026-09-01T01:27:24+02:00" level=info msg="running go-librespot 0.4.0"
Sep 01 01:27:24 stefans-speaker go-librespot[24591]: time="2026-09-01T01:27:24+02:00" level=debug msg="app state loaded"
Sep 01 01:27:24 stefans-speaker go-librespot[24591]: time="2026-09-01T01:27:24+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Sep 01 01:27:24 stefans-speaker go-librespot[24591]: time="2026-09-01T01:27:24+02: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]"
Sep 01 01:27:24 stefans-speaker go-librespot[24591]: time="2026-09-01T01:27:24+02: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]"
Sep 01 01:27:24 stefans-speaker go-librespot[24591]: time="2026-09-01T01:27:24+02: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]"
Sep 01 01:27:24 stefans-speaker go-librespot[24591]: time="2026-09-01T01:27:24+02:00" level=info msg="zeroconf server listening on port 36677"
Sep 01 01:27:24 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Sep 01 01:27:24 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Sep 01 01:27:24 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:27:24 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:27:24 stefans-speaker volumio[24258]: info: Starting MyVolumio Remote Streaming Endpoints
Sep 01 01:27:24 stefans-speaker go-librespot[24591]: time="2026-09-01T01:27:24+02:00" level=debug msg="obtained new client token: AAGB/YysZmZENhv1CIrCZX1RAFp+1tPhWC0MVc4oWyVB3uRwoQ3GhNrUHo+mobhWhlunC3nVTGauL42Av5iywkfPLDiOTx9PYPJpoRPGIEmuQ7kbtMeOdl+mOKkXwEK86T1WpOe5+RaNAdrfnvb+ZSk8LG8Hle8anCSl+DK3hIC3TsDBvlNIlv0K1Gvg50CgRJsK79fp+zMR0Ei3fbvh271kOQ6LBQhzFm1zId2BnL2f7QED99Fjxq7jvNY="
Sep 01 01:27:24 stefans-speaker volumio[24258]: info: MyVolumio login type: Token
Sep 01 01:27:24 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Sep 01 01:27:24 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Sep 01 01:27:24 stefans-speaker go-librespot[24591]: time="2026-09-01T01:27:24+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused"
Sep 01 01:27:24 stefans-speaker go-librespot[24591]: time="2026-09-01T01:27:24+02:00" level=debug msg="connected to ap-gew4.spotify.com:443"
Sep 01 01:27:24 stefans-speaker go-librespot[24591]: time="2026-09-01T01:27:24+02:00" level=debug msg="completed keyexchange"
Sep 01 01:27:24 stefans-speaker go-librespot[24591]: time="2026-09-01T01:27:24+02:00" level=debug msg="completed challenge"
Sep 01 01:27:24 stefans-speaker go-librespot[24591]: time="2026-09-01T01:27:24+02:00" level=info msg="authenticated AP" username="31************************cy"
Sep 01 01:27:24 stefans-speaker go-librespot[24591]: time="2026-09-01T01:27:24+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Sep 01 01:27:24 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Sep 01 01:27:24 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Sep 01 01:27:25 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Sep 01 01:27:25 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Sep 01 01:27:25 stefans-speaker volumio[24258]: info: Streaming services startup
Sep 01 01:27:25 stefans-speaker volumio[24258]: info: Starting Streaming Daemon
Sep 01 01:27:25 stefans-speaker sudo[24599]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:27:25 stefans-speaker volumio[24258]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Sep 01 01:27:25 stefans-speaker sudo[24599]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Sep 01 01:27:25 stefans-speaker sudo[24599]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:27:25 stefans-speaker sudo[24599]: pam_unix(sudo:session): session closed for user root
Sep 01 01:27:25 stefans-speaker volumio[24258]: info: Initializing connection to go-librespot Websocket
Sep 01 01:27:25 stefans-speaker volumio[24258]: error: Cannot start Volumio Streaming Daemon
Sep 01 01:27:25 stefans-speaker volumio[24258]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Sep 01 01:27:25 stefans-speaker volumio[24258]: sudo: unable to resolve host stefans-speaker: System error
Sep 01 01:27:25 stefans-speaker volumio[24258]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Sep 01 01:27:25 stefans-speaker volumio[24258]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Sep 01 01:27:26 stefans-speaker volumio[24258]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Sep 01 01:27:26 stefans-speaker volumio[24258]: info: MyVolumio token set successfully
Sep 01 01:27:26 stefans-speaker volumio[24258]: info: MYVOLUMIO: Adding device
Sep 01 01:27:26 stefans-speaker volumio[24258]: info: MYVOLUMIO: Evaluating Server
Sep 01 01:27:27 stefans-speaker volumio[24258]: info: MyVolumio status changed
Sep 01 01:27:27 stefans-speaker volumio[24258]: info: Streaming services startup
Sep 01 01:27:27 stefans-speaker volumio[24258]: info: Starting Streaming Daemon
Sep 01 01:27:27 stefans-speaker volumio[24258]: info: Removing browser output: myVolumio user plan is not superstar
Sep 01 01:27:27 stefans-speaker volumio[24258]: info: Removing audio output:
Sep 01 01:27:27 stefans-speaker volumio[24258]: info: Stoppping Tunnel 1
Sep 01 01:27:27 stefans-speaker sudo[24626]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:27:27 stefans-speaker sudo[24628]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:27:27 stefans-speaker sudo[24626]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Sep 01 01:27:27 stefans-speaker sudo[24626]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:27:27 stefans-speaker sudo[24628]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service
Sep 01 01:27:27 stefans-speaker sudo[24628]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 01 01:27:27 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 01 01:27:27 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 01 01:27:27 stefans-speaker sudo[24626]: pam_unix(sudo:session): session closed for user root
Sep 01 01:27:27 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 01 01:27:27 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 01 01:27:27 stefans-speaker volumio[24258]: error: Cannot start Volumio Streaming Daemon
Sep 01 01:27:27 stefans-speaker volumio[24258]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Sep 01 01:27:27 stefans-speaker volumio[24258]: sudo: unable to resolve host stefans-speaker: System error
Sep 01 01:27:27 stefans-speaker volumio[24258]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Sep 01 01:27:27 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 01 01:27:27 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 01 01:27:27 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 01 01:27:27 stefans-speaker systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 01 01:27:27 stefans-speaker sudo[24628]: pam_unix(sudo:session): session closed for user root
Sep 01 01:27:27 stefans-speaker volumio[24258]: info: Remote SSH Stopped
Sep 01 01:27:27 stefans-speaker volumio[24258]: info: Setting Geolocation for MyVolumio to eu9
Sep 01 01:27:27 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:27:27 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:27:27 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:27:27 stefans-speaker volumio[24258]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Sep 01 01:27:28 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Sep 01 01:27:28 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:27:28 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:27:28 stefans-speaker go-librespot[24631]: go-librespot daemon starting...
Sep 01 01:27:28 stefans-speaker go-librespot[24632]: time="2026-09-01T01:27:28+02:00" level=info msg="running go-librespot 0.4.0"
Sep 01 01:27:28 stefans-speaker go-librespot[24632]: time="2026-09-01T01:27:28+02:00" level=debug msg="app state loaded"
Sep 01 01:27:28 stefans-speaker go-librespot[24632]: time="2026-09-01T01:27:28+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Sep 01 01:27:28 stefans-speaker volumio[24258]: info: Updating MyVolumio device info
Sep 01 01:27:28 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:27:28 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:27:28 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:27:28 stefans-speaker go-librespot[24632]: time="2026-09-01T01:27:28+02: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]"
Sep 01 01:27:28 stefans-speaker go-librespot[24632]: time="2026-09-01T01:27:28+02: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]"
Sep 01 01:27:28 stefans-speaker go-librespot[24632]: time="2026-09-01T01:27:28+02: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]"
Sep 01 01:27:28 stefans-speaker go-librespot[24632]: time="2026-09-01T01:27:28+02:00" level=info msg="zeroconf server listening on port 41707"
Sep 01 01:27:28 stefans-speaker go-librespot[24632]: time="2026-09-01T01:27:28+02:00" level=debug msg="obtained new client token: AAGnBdvBm0Pu7vBaIpa60JoWJhXwXumZ50pVl+LhTbZgUAtc8pb/HSwZVSg8FHLhwTHM9TygT/VW15p/GgUiGzlwvbEuSwxGOIHtdnPbvALb3yPs0vM3a/7O3/FDm7I3r6RJEfRwMtjEzeufDZ1YGI07pa+aKV0RCfB8mbNkmpqpOAiX0AdhUr0gMp0SAxopG0XnK1diejm51RqhGdnxKhpa8Wyhk1Nc1j6zjGlG4wNGo32FfeWFJrsp7oY="
Sep 01 01:27:28 stefans-speaker go-librespot[24632]: time="2026-09-01T01:27:28+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Sep 01 01:27:28 stefans-speaker volumio[24258]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Sep 01 01:27:28 stefans-speaker go-librespot[24632]: time="2026-09-01T01:27:28+02:00" level=debug msg="completed keyexchange"
Sep 01 01:27:28 stefans-speaker go-librespot[24632]: time="2026-09-01T01:27:28+02:00" level=debug msg="completed challenge"
Sep 01 01:27:28 stefans-speaker go-librespot[24632]: time="2026-09-01T01:27:28+02:00" level=info msg="authenticated AP" username="31************************cy"
Sep 01 01:27:28 stefans-speaker volumio[24258]: info: Initializing connection to go-librespot Websocket
Sep 01 01:27:28 stefans-speaker go-librespot[24632]: time="2026-09-01T01:27:28+02:00" level=debug msg="new websocket client"
Sep 01 01:27:28 stefans-speaker volumio[24258]: info: Connection to go-librespot Websocket established
Sep 01 01:27:28 stefans-speaker go-librespot[24632]: time="2026-09-01T01:27:28+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Sep 01 01:27:28 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Sep 01 01:27:28 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Sep 01 01:27:28 stefans-speaker volumio[24258]: info: Connection to go-librespot Websocket closed
Sep 01 01:27:31 stefans-speaker volumio[24258]: info: MYVOLUMIO: Adding device
Sep 01 01:27:31 stefans-speaker volumio[24258]: info: MYVOLUMIO: Evaluating Server
Sep 01 01:27:31 stefans-speaker systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Sep 01 01:27:31 stefans-speaker systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:27:31 stefans-speaker systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Sep 01 01:27:31 stefans-speaker go-librespot[24648]: go-librespot daemon starting...
Sep 01 01:27:31 stefans-speaker go-librespot[24653]: time="2026-09-01T01:27:31+02:00" level=info msg="running go-librespot 0.4.0"
Sep 01 01:27:31 stefans-speaker go-librespot[24653]: time="2026-09-01T01:27:31+02:00" level=debug msg="app state loaded"
Sep 01 01:27:31 stefans-speaker go-librespot[24653]: time="2026-09-01T01:27:31+02:00" level=info msg="api server listening on 127.0.0.1:9879"
Sep 01 01:27:31 stefans-speaker volumio[24258]: info: Getting Spotify volume
Sep 01 01:27:31 stefans-speaker volumio[24258]: info: Initializing connection to go-librespot Websocket
Sep 01 01:27:31 stefans-speaker go-librespot[24653]: time="2026-09-01T01:27:31+02:00" level=debug msg="new websocket client"
Sep 01 01:27:31 stefans-speaker volumio[24258]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3
Sep 01 01:27:31 stefans-speaker volumio[24258]: info: Connection to go-librespot Websocket established
Sep 01 01:27:32 stefans-speaker volumio[24258]: info: CoreCommandRouter::volumioGetState
Sep 01 01:27:32 stefans-speaker volumio[24258]: info: CorePlayQueue::getTrack 0
Sep 01 01:27:32 stefans-speaker volumio[24258]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70
Sep 01 01:27:32 stefans-speaker volumio[24258]: SPOTIFY: SPOTIFY VOLUME undefined
Sep 01 01:27:32 stefans-speaker volumio[24258]: SPOTIFY: VOLUMIO VOLUME 70
Sep 01 01:27:32 stefans-speaker volumio[24258]: info: Aligning Spotify Volume to Volumio Volume
Sep 01 01:27:32 stefans-speaker volumio[24258]: info: CoreCommandRouter::volumioGetState
Sep 01 01:27:32 stefans-speaker volumio[24258]: info: CorePlayQueue::getTrack 0
Sep 01 01:27:32 stefans-speaker volumio[24258]: info: Setting Spotify Volume from Volumio: 70
Sep 01 01:27:32 stefans-speaker go-librespot[24653]: time="2026-09-01T01:27:32+02: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]"
Sep 01 01:27:32 stefans-speaker go-librespot[24653]: time="2026-09-01T01:27:32+02: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]"
Sep 01 01:27:32 stefans-speaker go-librespot[24653]: time="2026-09-01T01:27:32+02: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]"
Sep 01 01:27:32 stefans-speaker volumio[24258]: info: Setting Geolocation for MyVolumio to eu2
Sep 01 01:27:32 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:27:32 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:27:32 stefans-speaker volumio[24258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 01 01:27:32 stefans-speaker go-librespot[24653]: time="2026-09-01T01:27:32+02:00" level=info msg="zeroconf server listening on port 38339"
Sep 01 01:27:32 stefans-speaker go-librespot[24653]: time="2026-09-01T01:27:32+02:00" level=debug msg="obtained new client token: AAEEx2xGyzPXlX+8WJKSFTFwvQXNeK+xP5AO8gHSHYUl6+KAgi31OjYGhuRcCYOBoRGw+xDzRySzoZbQVGVC/GjeA0V1BhACCnVpsUmeZAM/cn/dazDpaAtQjaBl8i7YVtTKT484k0YgTCeiLnYUsxe73qElFWPCvOSMY1uRfZR0tM7gKZthjOwpJ/0V6x6qFzQrb5mC2vOHU1iulI9cxDrDIvEoPU0NAzBXSnvvxsIRkEhpARN6QCLnkyQ="
Sep 01 01:27:32 stefans-speaker go-librespot[24653]: time="2026-09-01T01:27:32+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070"
Sep 01 01:27:32 stefans-speaker go-librespot[24653]: time="2026-09-01T01:27:32+02:00" level=debug msg="completed keyexchange"
Sep 01 01:27:32 stefans-speaker go-librespot[24653]: time="2026-09-01T01:27:32+02:00" level=debug msg="completed challenge"
Sep 01 01:27:32 stefans-speaker go-librespot[24653]: time="2026-09-01T01:27:32+02:00" level=info msg="authenticated AP" username="31************************cy"
Sep 01 01:27:32 stefans-speaker go-librespot[24653]: time="2026-09-01T01:27:32+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS"
Sep 01 01:27:32 stefans-speaker systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Sep 01 01:27:32 stefans-speaker systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Sep 01 01:27:32 stefans-speaker volumio[24258]: info: Connection to go-librespot Websocket closed
Sep 01 01:27:32 stefans-speaker volumio[24258]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Sep 01 01:27:32 stefans-speaker volumio[24258]: Error: socket hang up
Sep 01 01:27:32 stefans-speaker volumio[24258]:     at connResetException (node:internal/errors:720:14)
Sep 01 01:27:32 stefans-speaker volumio[24258]:     at Socket.socketOnEnd (node:_http_client:519:23)
Sep 01 01:27:32 stefans-speaker volumio[24258]:     at Socket.emit (node:events:526:35)
Sep 01 01:27:32 stefans-speaker volumio[24258]:     at endReadableNT (node:internal/streams/readable:1376:12)
Sep 01 01:27:32 stefans-speaker volumio[24258]:     at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
Sep 01 01:27:32 stefans-speaker volumio[24258]:   code: 'ECONNRESET',
Sep 01 01:27:32 stefans-speaker volumio[24258]:   response: undefined
Sep 01 01:27:32 stefans-speaker volumio[24258]: }
Sep 01 01:27:32 stefans-speaker volumio[24258]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Sep 01 01:27:33 stefans-speaker sudo[24681]:  volumio : unable to resolve host stefans-speaker: System error
Sep 01 01:27:33 stefans-speaker sudo[24681]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-09-01 01:26'
Sep 01 01:27:33 stefans-speaker sudo[24681]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)"
NAME="Raspbian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
VOLUMIO_BUILD_VERSION="cfdc872d40b979cca36352a7333c940c38dc64b5"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Fri Dec  5 20:42:14 UTC 2025"
VOLUMIO_VERSION="4.073"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"